From: ericm Date: Fri, 12 Aug 2005 21:35:03 +0000 (+0000) Subject: various message adjustment (more verbose) for remote acl upcall and lsd X-Git-Tag: v1_7_100~918 X-Git-Url: https://git.whamcloud.com/?p=fs%2Flustre-release.git;a=commitdiff_plain;h=998fe313267246a66ca776c8838c0150917bca75 various message adjustment (more verbose) for remote acl upcall and lsd upcalls, for debugging. --- diff --git a/lustre/mds/mds_acl.c b/lustre/mds/mds_acl.c index 68eddf0..5012cad 100644 --- a/lustre/mds/mds_acl.c +++ b/lustre/mds/mds_acl.c @@ -58,7 +58,7 @@ static struct upcall_cache _rmtacl_upcall_cache; static struct list_head _rmtacl_upcall_hashtable[RMTACL_UPCALL_HASHSIZE]; #define RMTACL_UPCALL_PATH "/usr/bin/lacl_upcall" -#define RMTACL_ACQUIRE_EXPIRE (15) +#define RMTACL_ACQUIRE_EXPIRE (20) #define RMTACL_ENTRY_EXPIRE (0) #define RMTACL_ERR_ENTRY_EXPIRE (0) @@ -132,8 +132,8 @@ static int rmtacl_make_upcall(struct upcall_cache *cache, "/proc/fs/lustre/mds/lacl_upcall\n", argv[0], rc); } else { - CDEBUG(D_SEC, "Invoked upcall %s %s %s %s\n", - argv[0], argv[1], argv[2], argv[3]); + CDEBUG(D_SEC, "Invoked upcall %s %s %s %s %s %s\n", + argv[0], argv[1], argv[2], argv[3], argv[4], argv[5]); } return rc; } @@ -166,6 +166,7 @@ static int rmtacl_parse_downcall(struct upcall_cache *cache, goto out; if (copy_from_user(desc->res, rargs->res, rargs->reslen)) { + CERROR("can't copy from userspace\n"); desc->upcall_status = -EFAULT; goto out; } diff --git a/lustre/sec/upcall_cache.c b/lustre/sec/upcall_cache.c index ad4686a..6ce2e7f 100644 --- a/lustre/sec/upcall_cache.c +++ b/lustre/sec/upcall_cache.c @@ -68,7 +68,7 @@ static void free_entry(struct upcall_cache_entry *entry) LASSERT(cache->free_entry); LASSERT(atomic_read(&entry->ue_refcount) == 0); - CDEBUG(D_SEC, "destroy %s entry %p for key "LPU64"\n", + CDEBUG(D_SEC, "%s: destroy entry %p for key "LPU64"\n", cache->uc_name, entry, entry->ue_key); list_del(&entry->ue_hash); @@ -139,7 +139,6 @@ __get_entry(struct upcall_cache *cache, unsigned int hash, __u64 key, ENTRY; LASSERT(hash < cache->uc_hashsize); - head = &cache->uc_hashtable[hash]; find_again: @@ -222,12 +221,12 @@ find_again: /* we're interrupted or upcall failed * in the middle */ - CERROR("entry %p not refreshed: cur %lu, key "LPU64", " - "ref %d fl %u, ac %ld, ex %ld\n", - entry, get_seconds(), entry->ue_key, + CERROR("%s: entry %p not refreshed: key "LPU64", " + "ref %d fl %u, cur %lu, ex %ld/%ld\n", + cache->uc_name, entry, entry->ue_key, atomic_read(&entry->ue_refcount), - entry->ue_flags, entry->ue_acquire_expire, - entry->ue_expire); + entry->ue_flags, get_seconds(), + entry->ue_acquire_expire, entry->ue_expire); put_entry(entry); write_unlock(&cache->uc_hashlock); CERROR("Interrupted? Or check whether %s is in place\n", @@ -287,7 +286,8 @@ void upcall_cache_put_entry(struct upcall_cache_entry *entry) write_lock(&cache->uc_hashlock); LASSERTF(atomic_read(&entry->ue_refcount) > 0, - "entry %p: ref %d\n", entry, atomic_read(&entry->ue_refcount)); + "%s: entry %p: ref %d\n", cache->uc_name, entry, + atomic_read(&entry->ue_refcount)); put_entry(entry); write_unlock(&cache->uc_hashlock); } @@ -316,7 +316,8 @@ int upcall_cache_downcall(struct upcall_cache *cache, __u64 key, void *args) if (!found) { /* haven't found, it's possible */ write_unlock(&cache->uc_hashlock); - CWARN("key "LPU64" entry dosen't found\n", key); + CWARN("%s: key "LPU64" entry dosen't found\n", + cache->uc_name, key); RETURN(-EINVAL); } @@ -325,28 +326,31 @@ int upcall_cache_downcall(struct upcall_cache *cache, __u64 key, void *args) /* This should not happen, just give a warning * at this moment. */ - CWARN("entry %p(key "LPU64", ac %ld, ex %ld): " - "already valid???\n", entry, entry->ue_key, + CWARN("%s: entry %p(key "LPU64", cur %lu, ex %ld/%ld) " + "already valid\n", cache->uc_name, + entry, entry->ue_key, get_seconds(), entry->ue_acquire_expire, entry->ue_expire); GOTO(out, rc = 0); } - CWARN("stale entry %p: cur %lu, key "LPU64", ref %d, " - "fl %u, ac %ld, ex %ld\n", - entry, get_seconds(), entry->ue_key, - atomic_read(&entry->ue_refcount), entry->ue_flags, - entry->ue_acquire_expire, entry->ue_expire); + CWARN("%s: stale entry %p: key "LPU64", ref %d, fl %u, " + "cur %lu, ex %ld/%ld\n", + cache->uc_name, entry, entry->ue_key, + atomic_read(&entry->ue_refcount), + entry->ue_flags, get_seconds(), + entry->ue_acquire_expire, entry->ue_expire); GOTO(out, rc = -EINVAL); } if (!UC_CACHE_IS_ACQUIRING(entry) || UC_CACHE_IS_INVALID(entry) || UC_CACHE_IS_EXPIRED(entry)) { - CWARN("stale entry %p: cur %lu, key "LPU64", ref %d, " - "fl %u, ac %ld, ex %ld\n", - entry, get_seconds(), entry->ue_key, - atomic_read(&entry->ue_refcount), entry->ue_flags, - entry->ue_acquire_expire, entry->ue_expire); + CWARN("%s: invalid entry %p: key "LPU64", ref %d, fl %u, " + "cur %lu, ex %ld/%ld\n", + cache->uc_name, entry, entry->ue_key, + atomic_read(&entry->ue_refcount), + entry->ue_flags, get_seconds(), + entry->ue_acquire_expire, entry->ue_expire); GOTO(out, rc = -EINVAL); } @@ -367,8 +371,8 @@ int upcall_cache_downcall(struct upcall_cache *cache, __u64 key, void *args) } UC_CACHE_SET_VALID(entry); - CDEBUG(D_SEC, "create ucache entry %p(key "LPU64")\n", - entry, entry->ue_key); + CDEBUG(D_SEC, "%s: create ucache entry %p(key "LPU64")\n", + cache->uc_name, entry, entry->ue_key); out: wake_up_all(&entry->ue_waitq); write_unlock(&cache->uc_hashlock); @@ -386,7 +390,6 @@ void upcall_cache_flush_one(struct upcall_cache *cache, __u64 key) hash = cache->hash(cache, key); LASSERT(hash < cache->uc_hashsize); - head = &cache->uc_hashtable[hash]; write_lock(&cache->uc_hashlock); @@ -398,6 +401,12 @@ void upcall_cache_flush_one(struct upcall_cache *cache, __u64 key) } if (found) { + CWARN("%s: flush entry %p: key "LPU64", ref %d, fl %x, " + "cur %lu, ex %ld/%ld\n", + cache->uc_name, entry, entry->ue_key, + atomic_read(&entry->ue_refcount), entry->ue_flags, + get_seconds(), entry->ue_acquire_expire, + entry->ue_expire); UC_CACHE_SET_EXPIRED(entry); if (!atomic_read(&entry->ue_refcount)) free_entry(entry); diff --git a/lustre/utils/lacl_upcall.c b/lustre/utils/lacl_upcall.c index dec19f4..7a7164d 100644 --- a/lustre/utils/lacl_upcall.c +++ b/lustre/utils/lacl_upcall.c @@ -31,6 +31,7 @@ #include #include #include +#include #include #include @@ -41,6 +42,16 @@ #include #include +static int g_testing = 0; + +#define log_msg(fmt, args...) \ + { \ + if (g_testing) \ + printf(fmt, ## args); \ + else \ + syslog(LOG_ERR, fmt, ## args); \ + } + int switch_user_identity(uid_t uid) { gid_t gid; @@ -51,8 +62,10 @@ int switch_user_identity(uid_t uid) int i; /* originally must be root */ - if (getuid() != 0 || geteuid() != 0) + if (getuid() != 0 || geteuid() != 0) { + log_msg("non-root: %u/%u\n", getuid(), geteuid()); return -EPERM; + } /* nothing more is needed for root */ if (uid == 0) @@ -64,12 +77,16 @@ int switch_user_identity(uid_t uid) */ maxgroups = sysconf(_SC_NGROUPS_MAX); groups = malloc(maxgroups * sizeof(gid_t)); - if (!groups) + if (!groups) { + log_msg("memory alloc failure\n"); return -ENOMEM; + } pw = getpwuid(uid); - if (!pw) + if (!pw) { + log_msg("no such uid %u\n", uid); return -EPERM; + } gid = pw->pw_gid; @@ -88,16 +105,19 @@ int switch_user_identity(uid_t uid) endgrent(); if (setgroups(ngroups, groups) == -1) { + log_msg("set %d groups: %s\n", ngroups, strerror(errno)); free(groups); return -EPERM; } free(groups); if (setgid(gid) == -1) { + log_msg("setgid %u: %s\n", gid, strerror(errno)); return -EPERM; } if (setuid(uid) == -1) { + log_msg("setuid %u: %s\n", uid, strerror(errno)); return -EPERM; } @@ -163,6 +183,7 @@ void do_acl_command(uid_t uid, char *lroot, char *cmdline) } if (chdir(lroot) < 0) { + log_msg("chdir to %s: %s\n", lroot, strerror(errno)); printf("MDS: can't change dir\n"); return; } @@ -195,11 +216,19 @@ int main (int argc, char **argv) int pipeout[2], pipeerr[2], pid; int output_size, rd, childret; - if (argc != 6) + if (argc != 6) { + log_msg("invalid argc %d\n", argc); return -1; + } + + /* XXX temp for debugging */ + log_msg("enter: %s %s %s %s %s\n", + argv[1], argv[2], argv[3], argv[4], argv[5]); - if (strcmp(argv[4], "get") && strcmp(argv[4], "set")) + if (strcmp(argv[4], "get") && strcmp(argv[4], "set")) { + log_msg("invalid arg 4: %s\n", argv[4]); return -1; + } dc_args.key = strtoull(argv[1], NULL, 16); dc_args.res = output; @@ -300,10 +329,19 @@ wait_child: downcall: dc_fd = open(dc_name, O_WRONLY); - if (dc_fd != -1) { - write(dc_fd, &dc_args, sizeof(dc_args)); + if (dc_fd < 0) { + log_msg("can't open %s: %s\n", dc_name, strerror(errno)); + } else { + int rc; + + rc = write(dc_fd, &dc_args, sizeof(dc_args)); + if (rc != sizeof(dc_args)) + log_msg("write error: ret %d\n", rc); + close(dc_fd); } + /* XXX temp for debugging */ + log_msg("finished upcall\n"); return 0; } diff --git a/lustre/utils/lsd_upcall.c b/lustre/utils/lsd_upcall.c index 1fbd45a..e1fbf5b 100644 --- a/lustre/utils/lsd_upcall.c +++ b/lustre/utils/lsd_upcall.c @@ -410,7 +410,6 @@ int main (int argc, char **argv) fclose(conf_fp); } - do_downcall: if (testing) { show_result(&ioc_data); @@ -428,8 +427,9 @@ do_downcall: if (rc != sizeof(ioc_data)) { log_msg(testing, "partial write ret %d: %s\n", rc, strerror(errno)); + return 1; } - return (rc != sizeof(ioc_data)); + return 0; } }