Bug 15287 - Advanced winbindd call depth logging
Summary: Advanced winbindd call depth logging
Status: NEW
Alias: None
Product: Samba 4.1 and newer
Classification: Unclassified
Component: Winbind (show other bugs)
Version: 4.18.0rc1
Hardware: All All
: P5 normal (vote)
Target Milestone: ---
Assignee: Samba QA Contact
QA Contact: Samba QA Contact
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2023-01-19 09:21 UTC by Pavel Filipenský
Modified: 2023-01-26 15:08 UTC (History)
0 users

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Pavel Filipenský 2023-01-19 09:21:37 UTC
tevent-0.14 adds support for call depth tracking of requests and sub-requests.

This will be used in the main winbind process to:

1) Log the call depth in the debug header, e.g.:  depth=3
2) Indent the debug text by 4 spaces with every level of the depth


Example:

  37 [2023/01/18 18:40:26.523209, 10, pid=4171487, effective(0, 0), real(0, 0), class=winbind, depth=1] ../../source3/winbindd/winbindd.c:526(process_request_send)                                                
  36       process_request_send: process_request: request fn INTERFACE_VERSION                                                                                                                                     
  35 [2023/01/18 18:40:26.523221,  3, pid=4171487, effective(0, 0), real(0, 0), class=winbind, depth=1] ../../source3/winbindd/winbindd_misc.c:355(winbindd_interface_version)                                     
  34       winbindd_interface_version: [nss_winbind (4171930)]: request interface version (version = 32)                                                                                                           
  33 [2023/01/18 18:40:26.523245, 10, pid=4171487, effective(0, 0), real(0, 0), class=winbind, depth=1] ../../source3/winbindd/winbindd.c:610(process_request_written)                                             
  32       process_request_written: [nss_winbind(4171930):INTERFACE_VERSION]: delivered response to client                                                                                                         
  31 [2023/01/18 18:40:26.523315,  3, pid=4171487, effective(0, 0), real(0, 0), class=winbind, depth=1] ../../source3/winbindd/winbindd.c:498(process_request_send)                                                
  30       process_request_send: [nss_winbind (4171930)] Handling async request: GETPWNAM                                                                                                                          
  29 [2023/01/18 18:40:26.523325,  3, pid=4171487, effective(0, 0), real(0, 0), class=winbind, depth=2] ../../source3/winbindd/winbindd_getpwnam.c:59(winbindd_getpwnam_send)                                      
  28           [nss_winbind (4171930)] Winbind external command GETPWNAM start.                                                                                                                                    
  27           Query username 'ADDOMAIN/alice'.                                                                                                                                                                    
  26 [2023/01/18 18:40:26.523337,  5, pid=4171487, effective(0, 0), real(0, 0), class=winbind, depth=3] ../../source3/winbindd/wb_lookupname.c:52(wb_lookupname_send)                                              
  25               WB command lookupname start.                                                                                                                                                                    
  24               Search namespace 'ADDOMAIN' and domain 'ADDOMAIN' for name 'alice'.                                                                                                                             
  23 [2023/01/18 18:40:26.523357,  1, pid=4171487, effective(0, 0), real(0, 0), class=rpc_parse, depth=6] ../../librpc/ndr/ndr.c:490(ndr_print_function_debug)                                                     
  22                                wbint_LookupName: struct wbint_LookupName                                                                                                                                      
  21                                   in: struct wbint_LookupName                                                                                                                                                 
  20                                       domain                   : *                                                                                                                                            
  19                                           domain                   : 'ADDOMAIN'                                                                                                                               
  18                                       name                     : *                                                                                                                                            
  17                                           name                     : 'ALICE'                                                                                                                                  
  16                                       flags                    : 0x00000008 (8)                                                                                                                               
  15 [2023/01/18 18:40:26.535473, 10, pid=4171487, effective(0, 0), real(0, 0), class=winbind, depth=8] ../../source3/winbindd/winbindd_cache.c:4778(wcache_store_ndr)                                             
  14                                   could not fetch seqnum for domain ADDOMAIN                                                                                                                                  
  13 [2023/01/18 18:40:26.535513,  1, pid=4171487, effective(0, 0), real(0, 0), class=rpc_parse, depth=6] ../../librpc/ndr/ndr.c:490(ndr_print_function_debug)                                                     
  12                                wbint_LookupName: struct wbint_LookupName                                                                                                                                      
  11                                   out: struct wbint_LookupName                                                                                                                                                
  10                                       type                     : *                                                                                                                                            
   9                                           type                     : SID_NAME_USER (1)                                                                                                                        
   8                                       sid                      : *                                                                                                                                            
   7                                           sid                      : S-1-5-21-915529170-3196908094-4289846010-1107                                                                                            
   6                                       result                   : NT_STATUS_OK
Comment 1 Samba QA Contact 2023-01-26 15:08:12 UTC
This bug was referenced in samba master:

13d2db03973c4e26b2cff0925faab785a3c12494
e3e687b659ac0d60a0e1f0775ab3cc7181b3cc29
7ba3b1b09de327f77ee11b1c5ba3a77260ce2342
3b1b37b1cf8f3599f2970cea1d9f0daa36afe4af
a6c1211504bbfc84cae7545539ba38e35417dc42
4b6e8e1c1178bd0e3177b12b22d60c7e3c44c1af
51d559d8f498d9941b50953bfe33d9f4110c2c96
c2f8fde9f308b0962cbb4cfa4fffda8c770e14db