From: Christopher J. Morrone Date: Thu, 20 Feb 2014 19:08:44 +0000 (-0800) Subject: LU-4624 statahead: Improve statahead debug messages X-Git-Tag: 2.5.58~83 X-Git-Url: https://git.whamcloud.com/?p=fs%2Flustre-release.git;a=commitdiff_plain;h=c5f0bae20e88abb825dff546d7fd6437e34063f8;ds=sidebyside LU-4624 statahead: Improve statahead debug messages The statahead debug messages include the pid of the current process in their body. This is both redudant (because all lustre log messages contain the pid), and sometimes downright misleading. For instance the messages would say something like "stopping statahead thread 3446". One would probably think that 3446 is the pid of the process that is being stopped, but in fact it was the pid of the caller issuing the stop signal. We remove all superfluous pids from the messages. Next we have the ll_statahead_thread() and the ll_agl_thread() record their respective pids in their respective ptlrpc_thread structures. This allows to print the pid of the thread that we are trying to stop (which is actually useful info) from other threads, such as those calling ll_stop_statahead(). Change-Id: Id4def179e02e9097f3f22048192d45bdf15b0aa8 Signed-off-by: Christopher J. Morrone Reviewed-on: http://review.whamcloud.com/9360 Tested-by: Jenkins Tested-by: Maloo Reviewed-by: Fan Yong Reviewed-by: Lai Siyao Reviewed-by: Oleg Drokin --- diff --git a/lustre/llite/statahead.c b/lustre/llite/statahead.c index 8491001..da5734f 100644 --- a/lustre/llite/statahead.c +++ b/lustre/llite/statahead.c @@ -979,8 +979,9 @@ static int ll_agl_thread(void *arg) struct l_wait_info lwi = { 0 }; ENTRY; - CDEBUG(D_READA, "agl thread started: [pid %d] [parent %.*s]\n", - current_pid(), parent->d_name.len, parent->d_name.name); + thread->t_pid = current_pid(); + CDEBUG(D_READA, "agl thread started: sai %p, parent %.*s\n", + sai, parent->d_name.len, parent->d_name.name); atomic_inc(&sbi->ll_agl_total); spin_lock(&plli->lli_agl_lock); @@ -1029,8 +1030,8 @@ static int ll_agl_thread(void *arg) spin_unlock(&plli->lli_agl_lock); wake_up(&thread->t_ctl_waitq); ll_sai_put(sai); - CDEBUG(D_READA, "agl thread stopped: [pid %d] [parent %.*s]\n", - current_pid(), parent->d_name.len, parent->d_name.name); + CDEBUG(D_READA, "agl thread stopped: sai %p, parent %.*s\n", + sai, parent->d_name.len, parent->d_name.name); RETURN(0); } @@ -1042,8 +1043,8 @@ static void ll_start_agl(struct dentry *parent, struct ll_statahead_info *sai) struct task_struct *task; ENTRY; - CDEBUG(D_READA, "start agl thread: [pid %d] [parent %.*s]\n", - current_pid(), parent->d_name.len, parent->d_name.name); + CDEBUG(D_READA, "start agl thread: sai %p, parent %.*s\n", + sai, parent->d_name.len, parent->d_name.name); plli = ll_i2info(parent->d_inode); task = kthread_run(ll_agl_thread, parent, @@ -1079,8 +1080,9 @@ static int ll_statahead_thread(void *arg) struct page *page = NULL; ENTRY; - CDEBUG(D_READA, "statahead thread started: [pid %d] [parent %.*s]\n", - current_pid(), parent->d_name.len, parent->d_name.name); + thread->t_pid = current_pid(); + CDEBUG(D_READA, "statahead thread starting: sai %p, parent %.*s\n", + sai, parent->d_name.len, parent->d_name.name); op_data = ll_prep_md_op_data(NULL, dir, dir, NULL, 0, 0, LUSTRE_OPC_ANY, dir); @@ -1246,8 +1248,8 @@ out: spin_unlock(&plli->lli_agl_lock); wake_up(&agl_thread->t_ctl_waitq); - CDEBUG(D_READA, "stop agl thread: [pid %d]\n", - current_pid()); + CDEBUG(D_READA, "stop agl thread: sai %p pid %u\n", + sai, (unsigned int)agl_thread->t_pid); l_wait_event(agl_thread->t_ctl_waitq, thread_is_stopped(agl_thread), &lwi); @@ -1273,8 +1275,8 @@ out: wake_up(&thread->t_ctl_waitq); ll_sai_put(sai); dput(parent); - CDEBUG(D_READA, "statahead thread stopped: [pid %d] [parent %.*s]\n", - current_pid(), parent->d_name.len, parent->d_name.name); + CDEBUG(D_READA, "statahead thread stopped: sai %p, parent %.*s\n", + sai, parent->d_name.len, parent->d_name.name); return rc; } @@ -1305,8 +1307,8 @@ void ll_stop_statahead(struct inode *dir, void *key) spin_unlock(&lli->lli_sa_lock); wake_up(&thread->t_ctl_waitq); - CDEBUG(D_READA, "stop statahead thread: [pid %d]\n", - current_pid()); + CDEBUG(D_READA, "stop statahead thread: sai %p pid %u\n", + lli->lli_sai, (unsigned int)thread->t_pid); l_wait_event(thread->t_ctl_waitq, thread_is_stopped(thread), &lwi); @@ -1461,10 +1463,10 @@ ll_sai_unplug(struct ll_statahead_info *sai, struct ll_sa_entry *entry) CDEBUG(D_READA, "Statahead for dir "DFID" hit " "ratio too low: hit/miss "LPU64"/"LPU64 ", sent/replied "LPU64"/"LPU64", stopping " - "statahead thread: pid %d\n", + "statahead thread\n", PFID(&lli->lli_fid), sai->sai_hit, sai->sai_miss, sai->sai_sent, - sai->sai_replied, current_pid()); + sai->sai_replied); spin_lock(&lli->lli_sa_lock); if (!thread_is_stopped(thread)) thread_set_flags(thread, SVC_STOPPING); @@ -1647,8 +1649,8 @@ int do_statahead_enter(struct inode *dir, struct dentry **dentryp, GOTO(out, rc = -EAGAIN); } - CDEBUG(D_READA, "start statahead thread: [pid %d] [parent %.*s]\n", - current_pid(), parent->d_name.len, parent->d_name.name); + CDEBUG(D_READA, "start statahead thread: sai %p, parent %.*s\n", + sai, parent->d_name.len, parent->d_name.name); /* The sai buffer already has one reference taken at allocation time, * but as soon as we expose the sai by attaching it to the lli that default