From 1047abc159b4eb4ba4a7342a0969e16e9d4b4c69 Mon Sep 17 00:00:00 2001 From: Steve French Date: Tue, 11 Oct 2005 19:58:06 -0700 Subject: [PATCH] [CIFS] CIFS Stats improvements 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 --- fs/cifs/CHANGES | 2 +- fs/cifs/README | 11 ++++++++-- fs/cifs/cifs_debug.c | 49 +++++++++++++++++++++++++++++++++++++++++++- fs/cifs/cifs_debug.h | 5 ++++- fs/cifs/cifsglob.h | 6 +++++- fs/cifs/connect.c | 3 +++ fs/cifs/file.c | 3 +++ fs/cifs/netmisc.c | 2 +- fs/cifs/transport.c | 25 +++++++++++++++++++++- 9 files changed, 98 insertions(+), 8 deletions(-) diff --git a/fs/cifs/CHANGES b/fs/cifs/CHANGES index b2a938378b..f554a70c9c 100644 --- a/fs/cifs/CHANGES +++ b/fs/cifs/CHANGES @@ -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 ------------ diff --git a/fs/cifs/README b/fs/cifs/README index e7a3ce62d7..bb90941826 100644 --- a/fs/cifs/README +++ b/fs/cifs/README @@ -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 diff --git a/fs/cifs/cifs_debug.c b/fs/cifs/cifs_debug.c index 6f7810992d..f4054d695f 100644 --- a/fs/cifs/cifs_debug.c +++ b/fs/cifs/cifs_debug.c @@ -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; } diff --git a/fs/cifs/cifs_debug.h b/fs/cifs/cifs_debug.h index bf24d2828f..4304d9dcfb 100644 --- a/fs/cifs/cifs_debug.h +++ b/fs/cifs/cifs_debug.h @@ -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 diff --git a/fs/cifs/cifsglob.h b/fs/cifs/cifsglob.h index 729717281b..839a55667c 100644 --- a/fs/cifs/cifsglob.h +++ b/fs/cifs/cifsglob.h @@ -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 */ diff --git a/fs/cifs/connect.c b/fs/cifs/connect.c index 177289771a..a8f0cbada0 100644 --- a/fs/cifs/connect.c +++ b/fs/cifs/connect.c @@ -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; } } diff --git a/fs/cifs/file.c b/fs/cifs/file.c index 11806c879c..585a62aebd 100644 --- a/fs/cifs/file.c +++ b/fs/cifs/file.c @@ -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]; diff --git a/fs/cifs/netmisc.c b/fs/cifs/netmisc.c index 29e6efc559..f781468984 100644 --- a/fs/cifs/netmisc.c +++ b/fs/cifs/netmisc.c @@ -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 { diff --git a/fs/cifs/transport.c b/fs/cifs/transport.c index d8865fbd87..981ea0d8b9 100644 --- a/fs/cifs/transport.c +++ b/fs/cifs/transport.c @@ -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); -- 2.39.5