summaryrefslogtreecommitdiffstats
path: root/fs/cifs/trace.h (follow)
Commit message (Collapse)AuthorAgeFilesLines
* smb3: add trace point for oplock not foundSteve French2022-05-221-0/+1
| | | | | | | | | | In order to debug problems with server potentially sending us an oplock that we don't recognize (or a race with close and oplock break) it would be helpful to have a dynamic trace point for this case. New tracepoint is called trace_smb3_oplock_not_found Signed-off-by: Steve French <stfrench@microsoft.com>
* smb3: add trace point for lease not found issueSteve French2022-05-221-0/+1
| | | | | | | | | | When trying to debug problems with server sending us a lease we don't recognize, it would be helpful to have a dynamic trace point for this case. New tracepoint is called trace_smb3_lease_not_found Acked-by: Ronnie Sahlberg <lsahlber@redhat.com> Signed-off-by: Steve French <stfrench@microsoft.com>
* cifs: Split the smb3_add_credits tracepointDavid Howells2022-04-091-0/+7
| | | | | | | | | | | | | | | | | | | Split the smb3_add_credits tracepoint to make it more obvious when looking at the logs which line corresponds to what credit change. Also add a tracepoint for credit overflow when it's being added back. Note that it might be better to add another field to the tracepoint for the information rather than splitting it. It would also be useful to store the MID potentially, though that isn't available when the credits are first obtained. Signed-off-by: David Howells <dhowells@redhat.com> cc: Shyam Prasad N <nspmangalore@gmail.com> cc: Rohith Surabattula <rohiths.msft@gmail.com> cc: linux-cifs@vger.kernel.org Acked-by: Paulo Alcantara (SUSE) <pc@cjr.nz> Reviewed-by: Enzo Matsumiya <ematsumiya@suse.de> Signed-off-by: Steve French <stfrench@microsoft.com>
* smb3: add dynamic trace points for socket connectionSteve French2021-11-051-0/+71
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | In debugging user problems with ip address/DNS issues with smb3 mounts, we sometimes needed additional info on the hostname and ip address. Add two tracepoints, one to show socket connection success and one for failures to connect to the socket. Sample output: mount.cifs-14551 [005] ..... 7636.547906: smb3_connect_done: conn_id=0x1 server=localhost addr=127.0.0.1:445 mount.cifs-14558 [004] ..... 7642.405413: smb3_connect_done: conn_id=0x2 server=smfrench.file.core.windows.net addr=52.239.158.232:445 mount.cifs-14741 [005] ..... 7818.490716: smb3_connect_done: conn_id=0x3 server=::1 addr=[::1]:445/0%0 mount.cifs-14810 [000] ..... 7966.380337: smb3_connect_err: rc=-101 conn_id=0x4 server=::2 addr=[::2]:445/0%0 mount.cifs-14810 [000] ..... 7966.380356: smb3_connect_err: rc=-101 conn_id=0x4 server=::2 addr=[::2]:139/0%0 mount.cifs-14818 [003] ..... 7986.771992: smb3_connect_done: conn_id=0x5 server=127.0.0.9 addr=127.0.0.9:445 mount.cifs-14825 [008] ..... 8008.178109: smb3_connect_err: rc=-115 conn_id=0x6 server=124.23.0.9 addr=124.23.0.9:445 mount.cifs-14825 [008] ..... 8013.298085: smb3_connect_err: rc=-115 conn_id=0x6 server=124.23.0.9 addr=124.23.0.9:139 cifsd-14553 [006] ..... 8036.735615: smb3_reconnect: conn_id=0x1 server=localhost current_mid=32 cifsd-14743 [010] ..... 8036.735644: smb3_reconnect: conn_id=0x3 server=::1 current_mid=29 cifsd-14743 [010] ..... 8039.921740: smb3_connect_err: rc=-111 conn_id=0x3 server=::1 addr=[::1]:445/0%0 cifsd-14553 [008] ..... 8042.993894: smb3_connect_err: rc=-111 conn_id=0x1 server=localhost addr=127.0.0.1:445 cifsd-14743 [010] ..... 8042.993894: smb3_connect_err: rc=-111 conn_id=0x3 server=::1 addr=[::1]:445/0%0 cifsd-14553 [008] ..... 8046.065824: smb3_connect_err: rc=-111 conn_id=0x1 server=localhost addr=127.0.0.1:445 cifsd-14743 [010] ..... 8046.065824: smb3_connect_err: rc=-111 conn_id=0x3 server=::1 addr=[::1]:445/0%0 cifsd-14553 [008] ..... 8049.137796: smb3_connect_done: conn_id=0x1 server=localhost addr=127.0.0.1:445 cifsd-14743 [010] ..... 8049.137796: smb3_connect_done: conn_id=0x3 server=::1 addr=[::1]:445/0%0 Reviewed-by: Paulo Alcantara (SUSE) <pc@cjr.nz> Signed-off-by: Steve French <stfrench@microsoft.com>
* cifs: fix string declarations and assignments in tracepointsShyam Prasad N2021-05-271-12/+17
| | | | | | | | | | | | | We missed using the variable length string macros in several tracepoints. Fixed them in this change. There's probably more useful macros that we can use to print others like flags etc. But I'll submit sepawrate patches for those at a future date. Signed-off-by: Shyam Prasad N <sprasad@microsoft.com> Cc: <stable@vger.kernel.org> # v5.12 Signed-off-by: Steve French <stfrench@microsoft.com>
* cifs: Identify a connection by a conn_id.Shyam Prasad N2021-02-161-10/+26
| | | | | | | | | | | | | | | | | | | | | Introduced a new field conn_id in TCP_Server_Info structure. This is a non-persistent unique identifier maintained by the client for a connection to a file server. For this, a global counter named tcpSesNextId is maintained. On allocating a new TCP_Server_Info, this counter is incremented and assigned. Changed the dynamic tracepoints related to reconnects and crediting to be more informative (with conn_id printed). Debugging a crediting issue helped me understand the important things to print here. Always call dynamic tracepoints outside the scope of spinlocks. To do this, copy out the credits and in_flight fields of the server struct before dropping the lock. Signed-off-by: Shyam Prasad N <sprasad@microsoft.com> Reviewed-by: Pavel Shilovsky <pshilov@microsoft.com> Signed-off-by: Steve French <stfrench@microsoft.com>
* cifs: Tracepoints and logs for tracing credit changes.Shyam Prasad N2020-12-151-0/+4
| | | | | | | | | | | | | | There is at least one suspected bug in crediting changes in cifs.ko which has come up a few times in the discussions and in a customer case. This change adds tracepoints to the code which modifies the server credit values in any way. The goal is to be able to track the changes to the credit values of the session to be able to catch when there is a crediting bug. Signed-off-by: Shyam Prasad N <sprasad@microsoft.com> Signed-off-by: Steve French <stfrench@microsoft.com>
* smb3: add dynamic trace point to trace when credits obtainedSteve French2020-10-201-6/+12
| | | | | | | | | | | | | | | SMB3 crediting is used for flow control, and it can be useful to trace for problem determination how many credits were acquired and for which operation. Here is an example ("trace-cmd record -e *add_credits"): cifsd-9522    [010] ....  5995.202712: smb3_add_credits: server=localhost current_mid=0x12 credits=373 credits_to_add=10 cifsd-9522    [010] ....  5995.204040: smb3_add_credits: server=localhost current_mid=0x15 credits=400 credits_to_add=30 Reviewed-by: Aurelien Aptel <aaptel@suse.com> Signed-off-by: Steve French <stfrench@microsoft.com>
* smb311: Add tracepoints for new compound posix query infoSteve French2020-06-121-0/+3
| | | | | | | Add dynamic tracepoints for new SMB3.1.1. posix extensions query info level (100) Signed-off-by: Steve French <stfrench@microsoft.com> Reviewed-by: Aurelien Aptel <aaptel@suse.com>
* cifs: Add tracepoints for errors on flush or fsyncSteve French2020-02-061-0/+27
| | | | | | | | | | Makes it easier to debug errors on writeback that happen later, and are being returned on flush or fsync For example: writetest-17829 [002] .... 13583.407859: cifs_flush_err: ino=90 rc=-28 Signed-off-by: Steve French <stfrench@microsoft.com>
* smb3: add missing worker function for SMB3 change notifySteve French2019-09-161-0/+3
| | | | | | | | | | SMB3 change notify is important to allow applications to wait on directory change events of different types (e.g. adding and deleting files from others systems). Add worker functions for this. Acked-by: Aurelien Aptel <aaptel@suse.com> Signed-off-by: Steve French <stfrench@microsoft.com>
* smb3: add dynamic tracepoints for flush and closeSteve French2019-09-161-0/+35
| | | | | | | | | | | | | | | | | | | | | | We only had dynamic tracepoints on errors in flush and close, but may be helpful to trace enter and non-error exits for those. Sample trace examples (excerpts) from "cp" and "dd" show two of the new tracepoints. cp-22823 [002] .... 123439.179701: smb3_enter: _cifsFileInfo_put: xid=10 cp-22823 [002] .... 123439.179705: smb3_close_enter: xid=10 sid=0x98871327 tid=0xfcd585ff fid=0xc7f84682 cp-22823 [002] .... 123439.179711: smb3_cmd_enter: sid=0x98871327 tid=0xfcd585ff cmd=6 mid=43 cp-22823 [002] .... 123439.180175: smb3_cmd_done: sid=0x98871327 tid=0xfcd585ff cmd=6 mid=43 cp-22823 [002] .... 123439.180179: smb3_close_done: xid=10 sid=0x98871327 tid=0xfcd585ff fid=0xc7f84682 dd-22981 [003] .... 123696.946011: smb3_flush_enter: xid=24 sid=0x98871327 tid=0xfcd585ff fid=0x1917736f dd-22981 [003] .... 123696.946013: smb3_cmd_enter: sid=0x98871327 tid=0xfcd585ff cmd=7 mid=123 dd-22981 [003] .... 123696.956639: smb3_cmd_done: sid=0x98871327 tid=0x0 cmd=7 mid=123 dd-22981 [003] .... 123696.956644: smb3_flush_done: xid=24 sid=0x98871327 tid=0xfcd585ff fid=0x1917736f Signed-off-by: Steve French <stfrench@microsoft.com> Reviewed-by: Ronnie Sahlberg <lsahlber@redhat.com>
* cifs: Fix slab-out-of-bounds when tracing SMB tconPaulo Alcantara (SUSE)2019-03-231-3/+3
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | This patch fixes the following KASAN report: [ 779.044746] BUG: KASAN: slab-out-of-bounds in string+0xab/0x180 [ 779.044750] Read of size 1 at addr ffff88814f327968 by task trace-cmd/2812 [ 779.044756] CPU: 1 PID: 2812 Comm: trace-cmd Not tainted 5.1.0-rc1+ #62 [ 779.044760] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.12.0-0-ga698c89-prebuilt.qemu.org 04/01/2014 [ 779.044761] Call Trace: [ 779.044769] dump_stack+0x5b/0x90 [ 779.044775] ? string+0xab/0x180 [ 779.044781] print_address_description+0x6c/0x23c [ 779.044787] ? string+0xab/0x180 [ 779.044792] ? string+0xab/0x180 [ 779.044797] kasan_report.cold.3+0x1a/0x32 [ 779.044803] ? string+0xab/0x180 [ 779.044809] string+0xab/0x180 [ 779.044816] ? widen_string+0x160/0x160 [ 779.044822] ? vsnprintf+0x5bf/0x7f0 [ 779.044829] vsnprintf+0x4e7/0x7f0 [ 779.044836] ? pointer+0x4a0/0x4a0 [ 779.044841] ? seq_buf_vprintf+0x79/0xc0 [ 779.044848] seq_buf_vprintf+0x62/0xc0 [ 779.044855] trace_seq_printf+0x113/0x210 [ 779.044861] ? trace_seq_puts+0x110/0x110 [ 779.044867] ? trace_raw_output_prep+0xd8/0x110 [ 779.044876] trace_raw_output_smb3_tcon_class+0x9f/0xc0 [ 779.044882] print_trace_line+0x377/0x890 [ 779.044888] ? tracing_buffers_read+0x300/0x300 [ 779.044893] ? ring_buffer_read+0x58/0x70 [ 779.044899] s_show+0x6e/0x140 [ 779.044906] seq_read+0x505/0x6a0 [ 779.044913] vfs_read+0xaf/0x1b0 [ 779.044919] ksys_read+0xa1/0x130 [ 779.044925] ? kernel_write+0xa0/0xa0 [ 779.044931] ? __do_page_fault+0x3d5/0x620 [ 779.044938] do_syscall_64+0x63/0x150 [ 779.044944] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 779.044949] RIP: 0033:0x7f62c2c2db31 [ 779.044955] Code: fe ff ff 48 8d 3d 17 9e 09 00 48 83 ec 08 e8 96 02 02 00 66 0f 1f 44 00 00 8b 05 fa fc 2c 00 48 63 ff 85 c0 75 13 31 c0 0f 05 <48> 3d 00 f0 ff ff 77 57 f3 c3 0f 1f 44 00 00 55 53 48 89 d5 48 89 [ 779.044958] RSP: 002b:00007ffd6e116678 EFLAGS: 00000246 ORIG_RAX: 0000000000000000 [ 779.044964] RAX: ffffffffffffffda RBX: 0000560a38be9260 RCX: 00007f62c2c2db31 [ 779.044966] RDX: 0000000000002000 RSI: 00007ffd6e116710 RDI: 0000000000000003 [ 779.044966] RDX: 0000000000002000 RSI: 00007ffd6e116710 RDI: 0000000000000003 [ 779.044969] RBP: 00007f62c2ef5420 R08: 0000000000000000 R09: 0000000000000003 [ 779.044972] R10: ffffffffffffffa8 R11: 0000000000000246 R12: 00007ffd6e116710 [ 779.044975] R13: 0000000000002000 R14: 0000000000000d68 R15: 0000000000002000 [ 779.044981] Allocated by task 1257: [ 779.044987] __kasan_kmalloc.constprop.5+0xc1/0xd0 [ 779.044992] kmem_cache_alloc+0xad/0x1a0 [ 779.044997] getname_flags+0x6c/0x2a0 [ 779.045003] user_path_at_empty+0x1d/0x40 [ 779.045008] do_faccessat+0x12a/0x330 [ 779.045012] do_syscall_64+0x63/0x150 [ 779.045017] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 779.045019] Freed by task 1257: [ 779.045023] __kasan_slab_free+0x12e/0x180 [ 779.045029] kmem_cache_free+0x85/0x1b0 [ 779.045034] filename_lookup.part.70+0x176/0x250 [ 779.045039] do_faccessat+0x12a/0x330 [ 779.045043] do_syscall_64+0x63/0x150 [ 779.045048] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 779.045052] The buggy address belongs to the object at ffff88814f326600 which belongs to the cache names_cache of size 4096 [ 779.045057] The buggy address is located 872 bytes to the right of 4096-byte region [ffff88814f326600, ffff88814f327600) [ 779.045058] The buggy address belongs to the page: [ 779.045062] page:ffffea00053cc800 count:1 mapcount:0 mapping:ffff88815b191b40 index:0x0 compound_mapcount: 0 [ 779.045067] flags: 0x200000000010200(slab|head) [ 779.045075] raw: 0200000000010200 dead000000000100 dead000000000200 ffff88815b191b40 [ 779.045081] raw: 0000000000000000 0000000000070007 00000001ffffffff 0000000000000000 [ 779.045083] page dumped because: kasan: bad access detected [ 779.045085] Memory state around the buggy address: [ 779.045089] ffff88814f327800: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc [ 779.045093] ffff88814f327880: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc [ 779.045097] >ffff88814f327900: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc [ 779.045099] ^ [ 779.045103] ffff88814f327980: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc [ 779.045107] ffff88814f327a00: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc [ 779.045109] ================================================================== [ 779.045110] Disabling lock debugging due to kernel taint Correctly assign tree name str for smb3_tcon event. Signed-off-by: Paulo Alcantara (SUSE) <paulo@paulo.ac> Signed-off-by: Steve French <stfrench@microsoft.com>
* smb3: add dynamic tracepoints for simple fallocate and zero rangeSteve French2019-03-151-0/+6
| | | | | | | | | Can be helpful in debugging various xfstests that are currently skipped or failing due to missing features in our current implementation of fallocate. Signed-off-by: Steve French <stfrench@microsoft.com> Reviewed-by: Ronnie Sahlberg <lsahlber@redhat.com>
* smb3: Add dynamic trace points for various compounded smb3 opsSteve French2019-03-151-0/+117
| | | | | | | | | | Adds trace points for enter and exit (done vs. error) for: compounded query and setinfo, hardlink, rename, mkdir, rmdir, set_eof, delete (unlink) Signed-off-by: Steve French <stfrench@microsoft.com> Reviewed-by: Ronnie Sahlberg <lsahlber@redhat.com>
* smb3: add dynamic tracepoint for timeout waiting for creditsSteve French2019-03-151-0/+1
| | | | | | | | | To help debug credit starvation problems where we timeout waiting for server to grant the client credits. Signed-off-by: Steve French <stfrench@microsoft.com> Reviewed-by: Ronnie Sahlberg <lsahlber@redhat.com> Reviewed-by: Pavel Shilovsky <pshilov@microsoft.com>
* smb3: add dynamic trace point for query_info_enter/doneSteve French2019-03-061-0/+42
| | | | | | | | | | | | | | | | | | Adds dynamic trace points for the query_info_enter and query_info_done (no error) case. We only had one existing trace point related to this which was on query_info errors. Note that these two new tracepoints are for the non-compounded query_info paths. Sample output (from: trace-cmd record -e smb3_query_info*) ls-24140 [001] .... 27811.866068: smb3_query_info_enter: xid=7 sid=0xd2d00587 tid=0xb5441939 fid=0xcf082bac class=18 type=0x1 ls-24140 [001] .... 27811.867656: smb3_query_info_done: xid=7 sid=0xd2d00587 tid=0xb5441939 fid=0xcf082bac class=18 type=0x1 getcifsacl-24149 [005] .... 27854.759873: smb3_query_info_enter: xid=15 sid=0xd2d00587 tid=0xb5441939 fid=0x99896e72 class=0 type=0x3 getcifsacl-24149 [005] .... 27854.761730: smb3_query_info_done: xid=15 sid=0xd2d00587 tid=0xb5441939 fid=0x99896e72 class=0 type=0x3 Signed-off-by: Steve French <stfrench@microsoft.com> Reviewed-by: Pavel Shilovsky <pshilov@microsoft.com>
* smb3: add dynamic trace point for smb3_cmd_enterSteve French2019-03-061-0/+1
| | | | | | | | | Add tracepoint before sending an SMB3 command on the wire (ie add an smb3_cmd_enter tracepoint). This allows us to look in much more detail at response times (between request and response). Signed-off-by: Steve French <stfrench@microsoft.com> Reviewed-by: Pavel Shilovsky <pshilov@microsoft.com>
* smb3: improve dynamic tracing of open and posix mkdirSteve French2019-03-061-1/+40
| | | | | | | Add dynamic trace point for open_enter (and posix mkdir enter) Signed-off-by: Steve French <stfrench@microsoft.com> Reviewed-by: Pavel Shilovsky <pshilov@microsoft.com>
* smb3: Add tracepoints for read, write and query_dir enterSteve French2019-03-061-0/+3
| | | | | | | | | | Allows tracing begin (not just completion) of read, write and query_dir which may be helpful in finding slow requests and other timing information Signed-off-by: Steve French <stfrench@microsoft.com> Reviewed-by: Pavel Shilovsky <pshilov@microsoft.com> Reviewed-by: Ronnie Sahlberg <lsahlber@redhat.com>
* smb3: add tracepoints for query dirSteve French2019-03-061-0/+2
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | Adds two tracepoints - one for query_dir done (no err) and one for query_dir_err Sanple output: To start the trace in one window: trace-cmd record -e smb3_query_dir* Then in another window after doing an ls /mnt View the trace output by: trace-cmd show Sample output: TASK-PID CPU# |||| TIMESTAMP FUNCTION | | | |||| | | ls-24869 [007] .... 90695.452009: smb3_query_dir_done: xid=7 sid=0x5027d24d tid=0xb95cf25a fid=0xc41a8c3e offset=0x0 len=0x16 ls-24869 [000] .... 90695.452764: smb3_query_dir_done: xid=8 sid=0x5027d24d tid=0xb95cf25a fid=0xc41a8c3e offset=0x0 len=0x0 ls-24874 [003] .... 90701.506342: smb3_query_dir_done: xid=11 sid=0x5027d24d tid=0xb95cf25a fid=0x33ad3601 offset=0x0 len=0x8 ls-24874 [003] .... 90701.506917: smb3_query_dir_done: xid=12 sid=0x5027d24d tid=0xb95cf25a fid=0x33ad3601 offset=0x0 len=0x0 Reviewed-by: Pavel Shilovsky <pshilov@microsoft.com> Reviewed-by: Ronnie Sahlberg <lsahlber@redhat.com> Signed-off-by: Steve French <stfrench@microsoft.com>
* smb3: Cleanup license messThomas Gleixner2019-01-241-10/+0
| | | | | | | | | | | | | | | | | | | | | | | | | | | | Precise and non-ambiguous license information is important. The recently added aegis header file has a SPDX license identifier, which is nice, but at the same time it has a contradictionary license boiler plate text. SPDX-License-Identifier: GPL-2.0 versus * This program is free software; you can redistribute it and/or modify * it under the terms of the GNU General Public License as published by * the Free Software Foundation; either version 2 of the License, or * (at your option) any later version. Oh well. Assuming that the SPDX identifier is correct and according to x86/hyper-v contributions from Microsoft GPL V2 only is the usual license. Remove the boiler plate as it is wrong and even if correct it is redundant. Fixes: eccb4422cf97 ("smb3: Add ftrace tracepoints for improved SMB3 debugging") Signed-off-by: Thomas Gleixner <tglx@linutronix.de> Cc: Steve French <sfrench@samba.org> Cc: linux-cifs@vger.kernel.org Signed-off-by: Steve French <stfrench@microsoft.com>
* smb3: add trace point for tree connectionSteve French2018-11-021-0/+42
| | | | | | | | | | | | | | | | | | | | | | | In debugging certain scenarios, especially reconnect cases, it can be helpful to have a dynamic trace point for the result of tree connect. See sample output below from a reconnect event. The new event is 'smb3_tcon' TASK-PID CPU# |||| TIMESTAMP FUNCTION | | | |||| | | cifsd-6071 [001] .... 2659.897923: smb3_reconnect: server=localhost current_mid=0xa kworker/1:1-71 [001] .... 2666.026342: smb3_cmd_done: sid=0x0 tid=0x0 cmd=0 mid=0 kworker/1:1-71 [001] .... 2666.026576: smb3_cmd_err: sid=0xc49e1787 tid=0x0 cmd=1 mid=1 status=0xc0000016 rc=-5 kworker/1:1-71 [001] .... 2666.031677: smb3_cmd_done: sid=0xc49e1787 tid=0x0 cmd=1 mid=2 kworker/1:1-71 [001] .... 2666.031921: smb3_cmd_done: sid=0xc49e1787 tid=0x6e78f05f cmd=3 mid=3 kworker/1:1-71 [001] .... 2666.031923: smb3_tcon: xid=0 sid=0xc49e1787 tid=0x0 unc_name=\\localhost\test rc=0 kworker/1:1-71 [001] .... 2666.032097: smb3_cmd_done: sid=0xc49e1787 tid=0x6e78f05f cmd=11 mid=4 kworker/1:1-71 [001] .... 2666.032265: smb3_cmd_done: sid=0xc49e1787 tid=0x7912332f cmd=3 mid=5 kworker/1:1-71 [001] .... 2666.032266: smb3_tcon: xid=0 sid=0xc49e1787 tid=0x0 unc_name=\\localhost\IPC$ rc=0 kworker/1:1-71 [001] .... 2666.032386: smb3_cmd_done: sid=0xc49e1787 tid=0x7912332f cmd=11 mid=6 Signed-off-by: Steve French <stfrench@microsoft.com> Reviewed-by: Ronnie Sahlberg <lsahlber@redhat.com>
* smb3: add tracepoint for sending lease break responses to serverSteve French2018-10-241-0/+79
| | | | | | | | | | | | | | Be able to log a ftrace message on success and/or failure of sending a lease break response to the server. Example output: TASK-PID CPU# |||| TIMESTAMP FUNCTION | | | |||| | | kworker/1:1-5681 [001] .... 11123.530457: smb3_lease_done: sid=0x291e3e0f tid=0x8ba43071 lease_key=0x1852ca0d3ecd9b55847750a86716fde lease_state=0x0 Signed-off-by: Steve French <stfrench@microsoft.com> Reviewed-by: Aurelien Aptel <aaptel@suse.com>
* smb3: add tracepoint to catch cases where credit refund of failed op ↵Steve French2018-10-241-0/+30
| | | | | | | | | | | overlaps reconnect Add tracepoint to catch potential cases where a pending operation overlapping a reconnect could fail and incorrectly refund its credits causing the client to think it has more credits available than the server thinks it does. Signed-off-by: Steve French <stfrench@microsoft.com> Reviewed-by: Ronnie Sahlberg <lsahlber@redhat.com>
* smb3: add tracepoint for slow responsesSteve French2018-08-071-0/+37
| | | | | | | | | | | | | If responses take longer than one second from the server, we can optionally log them to dmesg in current cifs.ko code (CONFIG_CIFS_STATS2 must be configured and a /proc/fs/cifs/cifsFYI flag must be set), but can be more useful to log these via ftrace (tracepoint is smb3_slow_rsp) which is easier and more granular (still requires CONFIG_CIFS_STATS2 to be configured in the build though). Signed-off-by: Steve French <stfrench@microsoft.com> Reviewed-by: Pavel Shilovsky <pshilov@microsoft.com>
* smb3: add reconnect tracepointsSteve French2018-08-071-0/+26
| | | | | | | | | | | | | | | | | | | | | Add tracepoints for reconnecting an smb3 session Example output (from trace-cmd) with the patch (showing the session marked for reconnect, the stat failing, and then the subsequent SMB3 commands after the server comes back up). The "smb3_reconnect" event is the new one. cifsd-25993 [000] .... 29635.368265: smb3_reconnect: server=localhost current_mid=0x1e stat-26200 [001] .... 29638.516403: smb3_enter: cifs_revalidate_dentry_attr: xid=22 stat-26200 [001] .... 29648.723296: smb3_exit_err: cifs_revalidate_dentry_attr: xid=22 rc=-112 kworker/0:1-22830 [000] .... 29653.850947: smb3_cmd_done: sid=0x0 tid=0x0 cmd=0 mid=0 kworker/0:1-22830 [000] .... 29653.851191: smb3_cmd_err: sid=0x8ae4683c tid=0x0 cmd=1 mid=1 status=0xc0000016 rc=-5 kworker/0:1-22830 [000] .... 29653.855254: smb3_cmd_done: sid=0x8ae4683c tid=0x0 cmd=1 mid=2 kworker/0:1-22830 [000] .... 29653.855482: smb3_cmd_done: sid=0x8ae4683c tid=0x8084f30d cmd=3 mid=3 Signed-off-by: Steve French <stfrench@microsoft.com> Reviewed-by: Ronnie Sahlberg <lsahlber@redhat.com> Reviewed-by: Aurelien Aptel <aaptel@suse.com>
* smb3: add tracepoint for session expired or deletedSteve French2018-08-071-0/+1
| | | | | | | | | In debugging reconnection problems, want to be able to more easily trace cases in which the server has marked the SMB3 session expired or deleted (to distinguish from timeout cases). Signed-off-by: Steve French <stfrench@microsoft.com> Reviewed-by: Ronnie Sahlberg <lsahlber@redhat.com>
* smb3: Fix mode on mkdir on smb311 mountsSteve French2018-06-151-1/+2
| | | | | | mkdir was not passing the mode on smb3.11 mounts with posix extensions Signed-off-by: Steve French <stfrench@microsoft.com>
* smb3: add tracepoints for smb2/smb3 openSteve French2018-05-311-0/+86
| | | | | | | | | | | | | | | | | | | | add two tracepoints for open completion. One for error one for completion (open_done). Sample output below TASK-PID CPU# |||| TIMESTAMP FUNCTION | | | |||| | | bash-15348 [007] .... 42441.027492: smb3_enter: cifs_lookup: xid=45 bash-15348 [007] .... 42441.028214: smb3_cmd_err: sid=0x6173e4ce tid=0xa05150e6 cmd=5 mid=105 status=0xc0000034 rc=-2 bash-15348 [007] .... 42441.028219: smb3_open_err: xid=45 sid=0x6173e4ce tid=0xa05150e6 cr_opts=0x0 des_access=0x80 rc=-2 bash-15348 [007] .... 42441.028225: smb3_exit_done: cifs_lookup: xid=45 fop777-24560 [002] .... 42442.627617: smb3_enter: cifs_revalidate_dentry_attr: xid=46 fop777-24560 [003] .... 42442.628301: smb3_cmd_err: sid=0x6173e4ce tid=0xa05150e6 cmd=5 mid=106 status=0xc0000034 rc=-2 fop777-24560 [003] .... 42442.628319: smb3_open_err: xid=46 sid=0x6173e4ce tid=0xa05150e6 cr_opts=0x0 des_access=0x80 rc=-2 fop777-24560 [003] .... 42442.628335: smb3_enter: cifs_atomic_open: xid=47 fop777-24560 [003] .... 42442.629587: smb3_cmd_done: sid=0x6173e4ce tid=0xa05150e6 cmd=5 mid=107 fop777-24560 [003] .... 42442.629592: smb3_open_done: xid=47 sid=0x6173e4ce tid=0xa05150e6 fid=0xb8a0984d cr_opts=0x40 des_access=0x40000080 Signed-off-by: Steve French <smfrench@gmail.com>
* smb3: add additional ftrace entry points for entry/exit to cifs.koSteve French2018-05-301-29/+74
| | | | Signed-off-by: Steve French <smfrench@gmail.com>
* smb3: Add ftrace tracepoints for improved SMB3 debuggingSteve French2018-05-281-0/+298
Although dmesg logs and wireshark network traces can be helpful, being able to dynamically enable/disable tracepoints (in this case via the kernel ftrace mechanism) can also be helpful in more quickly debugging problems, and more selectively tracing the events related to the bug report. This patch adds 12 ftrace tracepoints to cifs.ko for SMB3 events in some obvious locations. Subsequent patches will add more as needed. Example use: trace-cmd record -e cifs <run test case> trace-cmd show Various trace events can be filtered. See: trace-cmd list | grep cifs for the current list of cifs tracepoints. Sample output (from mount and writing to a file): root@smf:/sys/kernel/debug/tracing/events/cifs# trace-cmd show <snip> mount.cifs-6633 [006] .... 7246.936461: smb3_cmd_done: pid=6633 tid=0x0 sid=0x0 cmd=0 mid=0 mount.cifs-6633 [006] .... 7246.936701: smb3_cmd_err: pid=6633 tid=0x0 sid=0x3d9cf8e5 cmd=1 mid=1 status=0xc0000016 rc=-5 mount.cifs-6633 [006] .... 7246.943055: smb3_cmd_done: pid=6633 tid=0x0 sid=0x3d9cf8e5 cmd=1 mid=2 mount.cifs-6633 [006] .... 7246.943298: smb3_cmd_done: pid=6633 tid=0xf9447636 sid=0x3d9cf8e5 cmd=3 mid=3 mount.cifs-6633 [006] .... 7246.943446: smb3_cmd_done: pid=6633 tid=0xf9447636 sid=0x3d9cf8e5 cmd=11 mid=4 mount.cifs-6633 [006] .... 7246.943659: smb3_cmd_done: pid=6633 tid=0xe1b781a sid=0x3d9cf8e5 cmd=3 mid=5 mount.cifs-6633 [006] .... 7246.943766: smb3_cmd_done: pid=6633 tid=0xe1b781a sid=0x3d9cf8e5 cmd=11 mid=6 mount.cifs-6633 [006] .... 7246.943937: smb3_cmd_done: pid=6633 tid=0xe1b781a sid=0x3d9cf8e5 cmd=5 mid=7 mount.cifs-6633 [006] .... 7246.944020: smb3_cmd_done: pid=6633 tid=0xe1b781a sid=0x3d9cf8e5 cmd=16 mid=8 mount.cifs-6633 [006] .... 7246.944091: smb3_cmd_done: pid=6633 tid=0xe1b781a sid=0x3d9cf8e5 cmd=16 mid=9 mount.cifs-6633 [006] .... 7246.944163: smb3_cmd_done: pid=6633 tid=0xe1b781a sid=0x3d9cf8e5 cmd=16 mid=10 mount.cifs-6633 [006] .... 7246.944218: smb3_cmd_err: pid=6633 tid=0xf9447636 sid=0x3d9cf8e5 cmd=11 mid=11 status=0xc0000225 rc=-2 mount.cifs-6633 [006] .... 7246.944219: smb3_fsctl_err: xid=0 fid=0xffffffffffffffff tid=0xf9447636 sid=0x3d9cf8e5 class=0 type=393620 rc=-2 mount.cifs-6633 [007] .... 7246.944353: smb3_cmd_done: pid=6633 tid=0xe1b781a sid=0x3d9cf8e5 cmd=16 mid=12 bash-2071 [000] .... 7256.903844: smb3_cmd_done: pid=2071 tid=0xe1b781a sid=0x3d9cf8e5 cmd=5 mid=13 bash-2071 [000] .... 7256.904172: smb3_cmd_done: pid=2071 tid=0xe1b781a sid=0x3d9cf8e5 cmd=16 mid=14 bash-2071 [000] .... 7256.904471: smb3_cmd_done: pid=2071 tid=0xe1b781a sid=0x3d9cf8e5 cmd=17 mid=15 bash-2071 [000] .... 7256.904950: smb3_cmd_done: pid=2071 tid=0xe1b781a sid=0x3d9cf8e5 cmd=5 mid=16 bash-2071 [000] .... 7256.905305: smb3_cmd_done: pid=2071 tid=0xe1b781a sid=0x3d9cf8e5 cmd=17 mid=17 bash-2071 [000] .... 7256.905688: smb3_cmd_done: pid=2071 tid=0xe1b781a sid=0x3d9cf8e5 cmd=6 mid=18 bash-2071 [000] .... 7256.905809: smb3_write_done: xid=0 fid=0xd628f511 tid=0xe1b781a sid=0x3d9cf8e5 offset=0x0 len=0x1b Signed-off-by: Steve French <stfrench@microsoft.com> Acked-by: Ronnie Sahlberg <lsahlber@redhat.com>
generated by cgit v1.2.3 (git 2.39.1) at 2024-12-26 04:41:12 +0100