[CIFS] CIFS Stats improvements
authorSteve French <sfrench@us.ibm.com>
Wed, 12 Oct 2005 02:58:06 +0000 (19:58 -0700)
committerSteve French <sfrench@us.ibm.com>
Wed, 12 Oct 2005 02:58:06 +0000 (19:58 -0700)
New cifs_writepages routine was not updated bytes written in cifs stats.
Also added ability to clear /proc/fs/cifs/Stats by writing (0 or 1) to it.
Signed-off-by: Steve French <sfrench@us.ibm.com>
fs/cifs/CHANGES
fs/cifs/README
fs/cifs/cifs_debug.c
fs/cifs/cifs_debug.h
fs/cifs/cifsglob.h
fs/cifs/connect.c
fs/cifs/file.c
fs/cifs/netmisc.c
fs/cifs/transport.c

index b2a938378bef66be4d48df34693ceef475e8918b..f554a70c9cf3a596652858826c175303baa39eec 100644 (file)
@@ -9,7 +9,7 @@ wsize and rsize can now be larger than negotiated buffer size if server
 supports large readx/writex, even when directio mount flag not specified.
 Write size will in many cases now be 16K instead of 4K which greatly helps
 file copy performance on lightly loaded networks.  Fix oops in dnotify
-when experimental config flag enabled.
+when experimental config flag enabled. Make cifsFYI more granular.
 
 Version 1.37
 ------------
index e7a3ce62d71b35c14a5507703eb93286e802afc9..bb90941826adb4e60d662d930aa293055c42cd2b 100644 (file)
@@ -482,9 +482,16 @@ These experimental features and tracing can be enabled by changing flags in
 kernel, e.g.  insmod cifs).  To enable a feature set it to 1 e.g.  to enable 
 tracing to the kernel message log type: 
 
-       echo 1 > /proc/fs/cifs/cifsFYI
+       echo 7 > /proc/fs/cifs/cifsFYI
        
-and for more extensive tracing including the start of smb requests and responses
+cifsFYI functions as a bit mask. Setting it to 1 enables additional kernel
+logging of various informational messages.  2 enables logging of non-zero
+SMB return codes while 4 enables logging of requests that take longer
+than one second to complete (except for byte range lock requests). 
+Setting it to 4 requires defining CONFIG_CIFS_STATS2 manually in the
+source code (typically by setting it in the beginning of cifsglob.h),
+and setting it to seven enables all three.  Finally, tracing
+the start of smb requests and responses can be enabled via:
 
        echo 1 > /proc/fs/cifs/traceSMB
 
index 6f7810992db3d6ec062d1b5ff109b7e1b4d2dff8..f4054d695f81f7cc3899b43a6b5149f5e2a3ac89 100644 (file)
@@ -203,6 +203,49 @@ cifs_debug_data_read(char *buf, char **beginBuffer, off_t offset,
 }
 
 #ifdef CONFIG_CIFS_STATS
+
+static int
+cifs_stats_write(struct file *file, const char __user *buffer,
+               unsigned long count, void *data)
+{
+        char c;
+        int rc;
+       struct list_head *tmp;
+       struct cifsTconInfo *tcon;
+
+        rc = get_user(c, buffer);
+        if (rc)
+                return rc;
+
+        if (c == '1' || c == 'y' || c == 'Y') {
+               read_lock(&GlobalSMBSeslock);
+               list_for_each(tmp, &GlobalTreeConnectionList) {
+                       tcon = list_entry(tmp, struct cifsTconInfo,
+                                       cifsConnectionList);
+                       atomic_set(&tcon->num_smbs_sent, 0);
+                       atomic_set(&tcon->num_writes, 0);
+                       atomic_set(&tcon->num_reads, 0);
+                       atomic_set(&tcon->num_oplock_brks, 0);
+                       atomic_set(&tcon->num_opens, 0);
+                       atomic_set(&tcon->num_closes, 0);
+                       atomic_set(&tcon->num_deletes, 0);
+                       atomic_set(&tcon->num_mkdirs, 0);
+                       atomic_set(&tcon->num_rmdirs, 0);
+                       atomic_set(&tcon->num_renames, 0);
+                       atomic_set(&tcon->num_t2renames, 0);
+                       atomic_set(&tcon->num_ffirst, 0);
+                       atomic_set(&tcon->num_fnext, 0);
+                       atomic_set(&tcon->num_fclose, 0);
+                       atomic_set(&tcon->num_hardlinks, 0);
+                       atomic_set(&tcon->num_symlinks, 0);
+                       atomic_set(&tcon->num_locks, 0);
+               }
+               read_unlock(&GlobalSMBSeslock);
+       }
+
+        return count;
+}
+
 static int
 cifs_stats_read(char *buf, char **beginBuffer, off_t offset,
                  int count, int *eof, void *data)
@@ -365,8 +408,10 @@ cifs_proc_init(void)
                                cifs_debug_data_read, NULL);
 
 #ifdef CONFIG_CIFS_STATS
-       create_proc_read_entry("Stats", 0, proc_fs_cifs,
+       pde = create_proc_read_entry("Stats", 0, proc_fs_cifs,
                                cifs_stats_read, NULL);
+       if (pde)
+               pde->write_proc = cifs_stats_write;
 #endif
        pde = create_proc_read_entry("cifsFYI", 0, proc_fs_cifs,
                                cifsFYI_read, NULL);
@@ -483,6 +528,8 @@ cifsFYI_write(struct file *file, const char __user *buffer,
                cifsFYI = 0;
        else if (c == '1' || c == 'y' || c == 'Y')
                cifsFYI = 1;
+       else if((c > '1') && (c <= '9'))
+               cifsFYI = (int) (c - '0'); /* see cifs_debug.h for meanings */
 
        return count;
 }
index bf24d2828f685764ce19b66bb05736560c9719c4..4304d9dcfb6c6501853b533f7f3d320fcbcd95bf 100644 (file)
@@ -26,6 +26,9 @@
 void cifs_dump_mem(char *label, void *data, int length);
 extern int traceSMB;           /* flag which enables the function below */
 void dump_smb(struct smb_hdr *, int);
+#define CIFS_INFO      0x01
+#define CIFS_RC        0x02
+#define CIFS_TIMER     0x04
 
 /*
  *     debug ON
@@ -36,7 +39,7 @@ void dump_smb(struct smb_hdr *, int);
 
 /* information message: e.g., configuration, major event */
 extern int cifsFYI;
-#define cifsfyi(format,arg...) if (cifsFYI) printk(KERN_DEBUG " " __FILE__ ": " format "\n" "" , ## arg)
+#define cifsfyi(format,arg...) if (cifsFYI & CIFS_INFO) printk(KERN_DEBUG " " __FILE__ ": " format "\n" "" , ## arg)
 
 #define cFYI(button,prspec) if (button) cifsfyi prspec
 
index 729717281b4086ccfbc155be88ad6192baa8045b..839a55667c3ca190e18e6dcada97a8d8f72d287e 100644 (file)
@@ -377,7 +377,11 @@ struct mid_q_entry {
        __u16 mid;              /* multiplex id */
        __u16 pid;              /* process id */
        __u32 sequence_number;  /* for CIFS signing */
-       struct timeval when_sent;       /* time when smb sent */
+       unsigned long when_alloc;  /* when mid was created */
+#ifdef CONFIG_CIFS_STATS2
+       unsigned long when_sent; /* time when smb send finished */
+       unsigned long when_received; /* when demux complete (taken off wire) */
+#endif
        struct cifsSesInfo *ses;        /* smb was sent to this server */
        struct task_struct *tsk;        /* task waiting for response */
        struct smb_hdr *resp_buf;       /* response buffer */
index 177289771abeaa3febe00cc4236467f1128002f6..a8f0cbada0f0ac23dfa4e40126ba72de0147b795 100644 (file)
@@ -605,6 +605,9 @@ cifs_demultiplex_thread(struct TCP_Server_Info *server)
 multi_t2_fnd:
                                task_to_wake = mid_entry->tsk;
                                mid_entry->midState = MID_RESPONSE_RECEIVED;
+#ifdef CONFIG_CIFS_STATS2
+                               mid_entry->when_received = jiffies;
+#endif
                                break;
                        }
                }
index 11806c879c4715e21cee08a102403cb191c633da..585a62aebd590c78ad838c089f8aed111b861de0 100644 (file)
@@ -1153,6 +1153,9 @@ retry:
                                          rc, bytes_written));
                                set_bit(AS_EIO, &mapping->flags);
                                SetPageError(page);
+                       } else {
+                               cifs_stats_bytes_written(cifs_sb->tcon,
+                                                        bytes_written);
                        }
                        for (i = 0; i < n_iov; i++) {
                                page = pvec.pages[first + i];
index 29e6efc5597c37d9d08e4007eb483d15a0fbdacd..f7814689844b2f4440b374024f92d7899349b29b 100644 (file)
@@ -813,7 +813,7 @@ map_smb_to_linux_error(struct smb_hdr *smb)
        if (smb->Flags2 & SMBFLG2_ERR_STATUS) {
                /* translate the newer STATUS codes to old style errors and then to POSIX errors */
                __u32 err = le32_to_cpu(smb->Status.CifsError);
-               if(cifsFYI)
+               if(cifsFYI & CIFS_RC)
                        cifs_print_status(err);
                ntstatus_to_dos(err, &smberrclass, &smberrcode);
        } else {
index d8865fbd876ab785c3c22d0032f93ea9b36ce137..981ea0d8b9cdaa4b06f53f7fdae975b41a1bffa6 100644 (file)
@@ -59,7 +59,9 @@ AllocMidQEntry(struct smb_hdr *smb_buffer, struct cifsSesInfo *ses)
                temp->pid = current->pid;
                temp->command = smb_buffer->Command;
                cFYI(1, ("For smb_command %d", temp->command));
-               do_gettimeofday(&temp->when_sent);
+       /*      do_gettimeofday(&temp->when_sent);*/ /* easier to use jiffies */
+               /* when mid allocated can be before when sent */
+               temp->when_alloc = jiffies;
                temp->ses = ses;
                temp->tsk = current;
        }
@@ -75,6 +77,9 @@ AllocMidQEntry(struct smb_hdr *smb_buffer, struct cifsSesInfo *ses)
 static void
 DeleteMidQEntry(struct mid_q_entry *midEntry)
 {
+#ifdef CONFIG_CIFS_STATS2
+       unsigned long now;
+#endif
        spin_lock(&GlobalMid_Lock);
        midEntry->midState = MID_FREE;
        list_del(&midEntry->qhead);
@@ -84,6 +89,22 @@ DeleteMidQEntry(struct mid_q_entry *midEntry)
                cifs_buf_release(midEntry->resp_buf);
        else
                cifs_small_buf_release(midEntry->resp_buf);
+#ifdef CONFIG_CIFS_STATS2
+       now = jiffies;
+       /* commands taking longer than one second are indications that
+          something is wrong, unless it is quite a slow link or server */
+       if((now - midEntry->when_alloc) > HZ) {
+               if((cifsFYI & CIFS_TIMER) && 
+                  (midEntry->command != SMB_COM_LOCKING_ANDX)) {
+                       printk(KERN_DEBUG " CIFS slow rsp: cmd %d mid %d",
+                              midEntry->command, midEntry->mid);
+                       printk(" A: 0x%lx S: 0x%lx R: 0x%lx\n",
+                              now - midEntry->when_alloc,
+                              now - midEntry->when_sent,
+                              now - midEntry->when_received);
+               }
+       }
+#endif
        mempool_free(midEntry, cifs_mid_poolp);
 }
 
@@ -382,6 +403,7 @@ SendReceive2(const unsigned int xid, struct cifsSesInfo *ses,
                      (struct sockaddr *) &(ses->server->addr.sockAddr));
 #ifdef CONFIG_CIFS_STATS2
        atomic_dec(&ses->server->inSend);
+       midQ->when_sent = jiffies;
 #endif
        if(rc < 0) {
                DeleteMidQEntry(midQ);
@@ -646,6 +668,7 @@ SendReceive(const unsigned int xid, struct cifsSesInfo *ses,
                      (struct sockaddr *) &(ses->server->addr.sockAddr));
 #ifdef CONFIG_CIFS_STATS2
        atomic_dec(&ses->server->inSend);
+       midQ->when_sent = jiffies;
 #endif
        if(rc < 0) {
                DeleteMidQEntry(midQ);