increased `make test` logging in syslog with "debug syslog format = always"

Douglas Bagnall douglas.bagnall at catalyst.net.nz
Wed Jul 26 03:22:55 UTC 2023 

hi Martin!

>>       Signed-off-by: Douglas Bagnall <douglas.bagnall at catalyst.net.nz>
>>
>> diff --git a/selftest/target/Samba4.pm b/selftest/target/Samba4.pm
>> index 0bd77e906d5..3eb2388e298 100755
>> --- a/selftest/target/Samba4.pm
>> +++ b/selftest/target/Samba4.pm
>> @@ -1220,6 +1220,7 @@ sub provision($$$$$$$$$$$)
>>           # fruit:copyfile is a global option
>>           fruit:copyfile = yes
>>
>> +       logging = file
>>           $extra_smbconf_options
>>
>>    [tmp]
>>
>>
> 
> Yes, that is in Samba3.pm, so will work around the problem.
> 
> The confusing thing is that MR 3034, as per Andrew's intention, should
> only change the logging format and not the logging destination.  If it
> does change the destination then that's a regression, so we should hunt
> it down and fix it.

Indeed, though I was already on some other well-bifurcated hunt.

Also I am not sure the lines Samba already put in syslog (some winbindd and smbd 
copyrights) are not a bug in make test. We're not testing the lines get there -- 
it's just kind of an accident. So squelching the lot with a shrug sort of works.

> Are you able to post examples of lines that end up in syslog?

There small and large attachment are `make test TESTS=auth` with and without 
ca7b7bde3915a821b1b99 reverted, grepping out the non-samba.

The messages are all at level 0. There are about 18 processes involved. I don't 
think they are all servers. Some of the lines in syslog don't end up in 
st/subunit or the terminal output (e.g. the "Kinit for" lines).

thanks,
Douglas
-------------- next part --------------
Jul 26 13:50:24 box samba[3448823]: 2023-07-26T01:50:24.291030+00:00 localdc.samba.example.com samba[3448823]:
Jul 26 13:50:24 box samba[3448823]: samba version 4.19.0pre1-DEVELOPERBUILD started.
Jul 26 13:50:24 box samba[3448823]: Copyright Andrew Tridgell and the Samba Team 1992-2023
Jul 26 13:50:24 box samba[3448823]: 2023-07-26T01:50:24.312448+00:00 localdc.samba.example.com samba[3448823]:
Jul 26 13:50:24 box samba[3448823]: binary_smbd_main: samba PID 3448823 was called with maxruntime 18000 - current ts 1690336224
Jul 26 13:50:24 box samba[3448823]: 2023-07-26T01:50:24.388755+00:00 localdc.samba.example.com samba[3448823]:
Jul 26 13:50:24 box samba[3448823]: binary_smbd_main: samba: using 'standard' process model
Jul 26 13:50:24 box samba[3448842]: 2023-07-26T01:50:24.452504+00:00 localdc.samba.example.com samba[3448842]:
Jul 26 13:50:24 box samba[3448842]: x/samba/bin/winbindd: [2023/07/26 01:50:24,  0] ../../lib/util/debug.c:1263(reopen_one_log)
Jul 26 13:50:24 box samba[3448842]: 2023-07-26T01:50:24.452585+00:00 localdc.samba.example.com samba[3448842]:
Jul 26 13:50:24 box samba[3448842]: x/samba/bin/winbindd:   reopen_one_log: Unable to open new log file '/usr/local/samba/var/log.winbindd': No such file or directory
Jul 26 13:50:24 box winbindd[3448846]: 2023-07-26T01:50:24.464001+00:00 localdc.samba.example.com winbindd[3448846]:
Jul 26 13:50:24 box winbindd[3448846]:   winbindd version 4.19.0pre1-DEVELOPERBUILD started.
Jul 26 13:50:24 box winbindd[3448846]:   Copyright Andrew Tridgell and the Samba Team 1992-2023
Jul 26 13:50:59 box x/sam[3449286]: x/samba/source4/scripting/bin/subunitrun samba.tests.auth_log -UAdministrator[3449286]: 2023-07-26T01:50:59.027462+00:00 localdc.samba.example.com [3449286]:
Jul 26 13:50:59 box x/sam[3449286]: x/samba/source4/scripting/bin/subunitrun samba.tests.auth_log -UAdministrator[3449286]: Kinit for Administrator at SAMBA.EXAMPLE.COM to access localdc failed: Preauthentication failed
Jul 26 13:50:59 box x/sam[3449286]: x/samba/source4/scripting/bin/subunitrun samba.tests.auth_log -UAdministrator[3449286]: 2023-07-26T01:50:59.039512+00:00 localdc.samba.example.com [3449286]:
Jul 26 13:50:59 box x/sam[3449286]: x/samba/source4/scripting/bin/subunitrun samba.tests.auth_log -UAdministrator[3449286]: Kinit for badUser at SAMBA.EXAMPLE.COM to access localdc failed: Client not found in Kerberos database
Jul 26 13:51:13 box x/sam[3449505]: x/samba/source4/scripting/bin/subunitrun samba.tests.auth_log_netlogon_bad_creds -UAdministrator[3449505]: 2023-07-26T01:51:13.268390+00:00 localdc.samba.example.com [3449505]:
Jul 26 13:51:13 box x/sam[3449505]: x/samba/source4/scripting/bin/subunitrun samba.tests.auth_log_netlogon_bad_creds -UAdministrator[3449505]: Failed to bind to uuid 12345678-1234-abcd-ef00-01234567cffb for ncalrpc:[DEFAULT,schannel,abstract_syntax=12345678-1234-abcd-ef00-01234567cffb/0x00000001,ncalrpc_dir=x/samba/st/ad_dc_ntvfs/ncalrpc] NT_STATUS_NO_TRUST_SAM_ACCOUNT
Jul 26 13:51:13 box x/sam[3449505]: x/samba/source4/scripting/bin/subunitrun samba.tests.auth_log_netlogon_bad_creds -UAdministrator[3449505]: 2023-07-26T01:51:13.373894+00:00 localdc.samba.example.com [3449505]:
Jul 26 13:51:13 box x/sam[3449505]: x/samba/source4/scripting/bin/subunitrun samba.tests.auth_log_netlogon_bad_creds -UAdministrator[3449505]: Failed to bind to uuid 12345678-1234-abcd-ef00-01234567cffb for ncalrpc:[DEFAULT,schannel,abstract_syntax=12345678-1234-abcd-ef00-01234567cffb/0x00000001,ncalrpc_dir=x/samba/st/ad_dc_ntvfs/ncalrpc] NT_STATUS_ACCESS_DENIED
Jul 26 13:51:13 box samba[3448827]: 2023-07-26T01:51:13.476649+00:00 localdc.samba.example.com samba[3448827]:
Jul 26 13:51:13 box samba[3448827]: CVE-2022-38023: client_account[NetLogonBad] computer_name[NetLogonBad] schannel_type[2] client_negotiate_flags[0x0]  NT_STATUS_DOWNGRADE_DETECTED reject_des[1] reject_md5[1]
Jul 26 13:51:13 box samba[3448827]: 2023-07-26T01:51:13.580226+00:00 localdc.samba.example.com samba[3448827]:
Jul 26 13:51:13 box samba[3448827]: CVE-2022-38023: client_account[NetLogonBad] computer_name[NetLogonBad] schannel_type[2] client_negotiate_flags[0x4000]  NT_STATUS_DOWNGRADE_DETECTED reject_des[0] reject_md5[1]
Jul 26 13:51:42 box samba[3449939]: 2023-07-26T01:51:42.906769+00:00 dc7.samba2008r2.example.com samba[3449939]:
Jul 26 13:51:42 box samba[3449939]: samba version 4.19.0pre1-DEVELOPERBUILD started.
Jul 26 13:51:42 box samba[3449939]: Copyright Andrew Tridgell and the Samba Team 1992-2023
Jul 26 13:51:42 box samba[3449939]: 2023-07-26T01:51:42.927742+00:00 dc7.samba2008r2.example.com samba[3449939]:
Jul 26 13:51:42 box samba[3449939]: binary_smbd_main: samba PID 3449939 was called with maxruntime 18000 - current ts 1690336302
Jul 26 13:51:43 box samba[3449939]: 2023-07-26T01:51:43.005171+00:00 dc7.samba2008r2.example.com samba[3449939]:
Jul 26 13:51:43 box samba[3449939]: binary_smbd_main: samba: using 'standard' process model
Jul 26 13:51:43 box samba[3449949]: 2023-07-26T01:51:43.014046+00:00 dc7.samba2008r2.example.com samba[3449949]:
Jul 26 13:51:43 box samba[3449949]: Attempting to autogenerate TLS self-signed keys for https for hostname 'DC7.samba2008r2.example.com'
Jul 26 13:51:43 box samba[3449943]: 2023-07-26T01:51:43.046728+00:00 dc7.samba2008r2.example.com samba[3449943]:
Jul 26 13:51:43 box samba[3449943]: x/samba/bin/smbd: [2023/07/26 01:51:43,  0] ../../lib/util/debug.c:1263(reopen_one_log)
Jul 26 13:51:43 box samba[3449943]: 2023-07-26T01:51:43.046815+00:00 dc7.samba2008r2.example.com samba[3449943]:
Jul 26 13:51:43 box samba[3449943]: x/samba/bin/smbd:   reopen_one_log: Unable to open new log file '/usr/local/samba/var/log.smbd': No such file or directory
Jul 26 13:51:43 box samba[3449953]: 2023-07-26T01:51:43.060096+00:00 dc7.samba2008r2.example.com samba[3449953]:
Jul 26 13:51:43 box samba[3449953]: x/samba/bin/winbindd: [2023/07/26 01:51:43,  0] ../../lib/util/debug.c:1263(reopen_one_log)
Jul 26 13:51:43 box samba[3449953]: 2023-07-26T01:51:43.060189+00:00 dc7.samba2008r2.example.com samba[3449953]:
Jul 26 13:51:43 box samba[3449953]: x/samba/bin/winbindd:   reopen_one_log: Unable to open new log file '/usr/local/samba/var/log.winbindd': No such file or directory
Jul 26 13:51:43 box smbd[3449947]: 2023-07-26T01:51:43.062225+00:00 dc7.samba2008r2.example.com smbd[3449947]:
Jul 26 13:51:43 box smbd[3449947]:   smbd version 4.19.0pre1-DEVELOPERBUILD started.
Jul 26 13:51:43 box smbd[3449947]:   Copyright Andrew Tridgell and the Samba Team 1992-2023
Jul 26 13:51:43 box winbindd[3449957]: 2023-07-26T01:51:43.071586+00:00 dc7.samba2008r2.example.com winbindd[3449957]:
Jul 26 13:51:43 box winbindd[3449957]:   winbindd version 4.19.0pre1-DEVELOPERBUILD started.
Jul 26 13:51:43 box winbindd[3449957]:   Copyright Andrew Tridgell and the Samba Team 1992-2023
Jul 26 13:51:45 box samba[3449949]: 2023-07-26T01:51:45.909650+00:00 dc7.samba2008r2.example.com samba[3449949]:
Jul 26 13:51:45 box samba[3449949]: TLS self-signed keys generated OK
Jul 26 13:52:00 box samba[3450109]: 2023-07-26T01:52:00.347362+00:00 dc6.samba2003.example.com samba[3450109]:
Jul 26 13:52:00 box samba[3450109]: samba version 4.19.0pre1-DEVELOPERBUILD started.
Jul 26 13:52:00 box samba[3450109]: Copyright Andrew Tridgell and the Samba Team 1992-2023
Jul 26 13:52:00 box samba[3450109]: 2023-07-26T01:52:00.368814+00:00 dc6.samba2003.example.com samba[3450109]:
Jul 26 13:52:00 box samba[3450109]: binary_smbd_main: samba PID 3450109 was called with maxruntime 18000 - current ts 1690336320
Jul 26 13:52:00 box samba[3450109]: 2023-07-26T01:52:00.446946+00:00 dc6.samba2003.example.com samba[3450109]:
Jul 26 13:52:00 box samba[3450109]: binary_smbd_main: samba: using 'standard' process model
Jul 26 13:52:00 box samba[3450119]: 2023-07-26T01:52:00.454858+00:00 dc6.samba2003.example.com samba[3450119]:
Jul 26 13:52:00 box samba[3450119]: Attempting to autogenerate TLS self-signed keys for https for hostname 'DC6.samba2003.example.com'
Jul 26 13:52:00 box samba[3450113]: 2023-07-26T01:52:00.488435+00:00 dc6.samba2003.example.com samba[3450113]:
Jul 26 13:52:00 box samba[3450113]: x/samba/bin/smbd: [2023/07/26 01:52:00,  0] ../../lib/util/debug.c:1263(reopen_one_log)
Jul 26 13:52:00 box samba[3450113]: 2023-07-26T01:52:00.488522+00:00 dc6.samba2003.example.com samba[3450113]:
Jul 26 13:52:00 box samba[3450113]: x/samba/bin/smbd:   reopen_one_log: Unable to open new log file '/usr/local/samba/var/log.smbd': No such file or directory
Jul 26 13:52:00 box smbd[3450117]: 2023-07-26T01:52:00.501708+00:00 dc6.samba2003.example.com smbd[3450117]:
Jul 26 13:52:00 box smbd[3450117]:   smbd version 4.19.0pre1-DEVELOPERBUILD started.
Jul 26 13:52:00 box smbd[3450117]:   Copyright Andrew Tridgell and the Samba Team 1992-2023
Jul 26 13:52:00 box samba[3450123]: 2023-07-26T01:52:00.513226+00:00 dc6.samba2003.example.com samba[3450123]:
Jul 26 13:52:00 box samba[3450123]: x/samba/bin/winbindd: [2023/07/26 01:52:00,  0] ../../lib/util/debug.c:1263(reopen_one_log)
Jul 26 13:52:00 box samba[3450123]: 2023-07-26T01:52:00.513696+00:00 dc6.samba2003.example.com samba[3450123]:
Jul 26 13:52:00 box samba[3450123]: x/samba/bin/winbindd:   reopen_one_log: Unable to open new log file '/usr/local/samba/var/log.winbindd': No such file or directory
Jul 26 13:52:00 box winbindd[3450129]: 2023-07-26T01:52:00.527903+00:00 dc6.samba2003.example.com winbindd[3450129]:
Jul 26 13:52:00 box winbindd[3450129]:   winbindd version 4.19.0pre1-DEVELOPERBUILD started.
Jul 26 13:52:00 box winbindd[3450129]:   Copyright Andrew Tridgell and the Samba Team 1992-2023
Jul 26 13:52:02 box samba[3450119]: 2023-07-26T01:52:02.405662+00:00 dc6.samba2003.example.com samba[3450119]:
Jul 26 13:52:02 box samba[3450119]: TLS self-signed keys generated OK
Jul 26 13:52:20 box samba[3450109]: 2023-07-26T01:52:20.641106+00:00 dc6.samba2003.example.com samba[3450109]:
Jul 26 13:52:20 box samba[3450109]: server_stdin_handler: samba: EOF on stdin - PID 3450109 terminating
Jul 26 13:52:20 box samba[3449939]: 2023-07-26T01:52:20.641158+00:00 dc7.samba2008r2.example.com samba[3449939]:
Jul 26 13:52:20 box samba[3449939]: server_stdin_handler: samba: EOF on stdin - PID 3449939 terminating
Jul 26 13:52:20 box samba[3448823]: 2023-07-26T01:52:20.645642+00:00 localdc.samba.example.com samba[3448823]:
Jul 26 13:52:20 box samba[3448823]: server_stdin_handler: samba: EOF on stdin - PID 3448823 terminating
-------------- next part --------------
Jul 26 13:54:07 box winbindd[3450763]: [2023/07/26 01:54:07.254743,  0] ../../source3/winbindd/winbindd.c:1441(main)
Jul 26 13:54:07 box winbindd[3450763]:   winbindd version 4.19.0pre1-DEVELOPERBUILD started.
Jul 26 13:54:07 box winbindd[3450763]:   Copyright Andrew Tridgell and the Samba Team 1992-2023
Jul 26 13:55:24 box smbd[3451890]: [2023/07/26 01:55:24.096917,  0] ../../source3/smbd/server.c:1746(main)
Jul 26 13:55:24 box smbd[3451890]:   smbd version 4.19.0pre1-DEVELOPERBUILD started.
Jul 26 13:55:24 box smbd[3451890]:   Copyright Andrew Tridgell and the Samba Team 1992-2023
Jul 26 13:55:24 box winbindd[3451900]: [2023/07/26 01:55:24.126694,  0] ../../source3/winbindd/winbindd.c:1441(main)
Jul 26 13:55:24 box winbindd[3451900]:   winbindd version 4.19.0pre1-DEVELOPERBUILD started.
Jul 26 13:55:24 box winbindd[3451900]:   Copyright Andrew Tridgell and the Samba Team 1992-2023
Jul 26 13:55:41 box smbd[3452027]: [2023/07/26 01:55:41.561793,  0] ../../source3/smbd/server.c:1746(main)
Jul 26 13:55:41 box smbd[3452027]:   smbd version 4.19.0pre1-DEVELOPERBUILD started.
Jul 26 13:55:41 box smbd[3452027]:   Copyright Andrew Tridgell and the Samba Team 1992-2023
Jul 26 13:55:41 box winbindd[3452037]: [2023/07/26 01:55:41.574195,  0] ../../source3/winbindd/winbindd.c:1441(main)
Jul 26 13:55:41 box winbindd[3452037]:   winbindd version 4.19.0pre1-DEVELOPERBUILD started.
Jul 26 13:55:41 box winbindd[3452037]:   Copyright Andrew Tridgell and the Samba Team 1992-2023

More information about the samba-technical mailing list