Flapping notify tests

Wed Aug 29 19:36:03 UTC 2018

On Wed, Aug 29, 2018 at 09:14:27AM +1200, Andrew Bartlett wrote:
> G'Day Jeremy,
> 
> Following up from our recent phone call and your gallant offer to
> assist, here are some notify failures I've seen recently that I would
> love to see resolved, as they flap reasonably often:

I'll try and take a look at these, it would be really
good for the fileserver tests to be 100% robust (and
they really should be).

> [93(538)/94 at 9m51s] samba3.smb2.notify-inotify(fileserver)
> smbtorture 4.10.0pre1-DEVELOPERBUILD
> Using seed 1535488533
> Testing change notify of a rename with inotify
> UNEXPECTED(failure): samba3.smb2.notify-inotify.inotify-
> rename(fileserver)
> REASON: Exception: Exception: ../source4/torture/smb2/notify.c:2441:
> status was NT_STATUS_CANCELLED, expected NT_STATUS_OK: smb2_notify_recv
> failed
> 
> TESTING CHANGE NOTIFY REPLY ALIGNMENT
> UNEXPECTED(failure): samba3.raw.notify.alignment(nt4_dc)
> REASON: Exception: Exception: ../source4/torture/raw/notify.c:1970: Expression `notify.nttrans.out.num_changes == num_names' failed:
> 
> TESTING CHANGE NOTIFY COMPLETION FILTERS
> Testing mkdir
> Testing create file
> UNEXPECTED(failure): samba3.raw.notify.mask(nt4_dc)
> REASON: Exception: Exception: ../source4/torture/raw/notify.c:814: notify.nttrans.out.changes[0].action was 2 (0x2), expected 1 (0x1): nchanges=1 action=2 expectedAction=1 filter=0x00000002
> 
> [205(1156)/565 at 11m56s] samba3.smb2.notify(nt4_dc)
> TESTING CHANGE NOTIFY ON DIRECTORIES
> Testing notify cancel
> Testing notify mkdir
> Testing notify rmdir
> Testing notify mkdir - rmdir - mkdir - rmdir
> Testing buffered notify on create of 10 files
> Testing notify on unlink for the first file
> UNEXPECTED(failure): samba3.smb2.notify.dir(nt4_dc)
> REASON: Exception: Exception: (../source4/torture/smb2/notify.c:394) wrong value for notify.smb2.out.num_changes  0x9 should be 0xa
> 
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:06 2018 CEST(131813097660000000) => Mon Nov 12 11:56:06 2018 CET(131864937660000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:06 2018 CEST(131813097660000000) => Mon Nov 12 11:56:06 2018 CET(131864937660000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:08 2018 CEST(131813097680000000) => Mon Nov 12 11:56:08 2018 CET(131864937680000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:08 2018 CEST(131813097680000000) => Mon Nov 12 11:56:08 2018 CET(131864937680000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:08 2018 CEST(131813097680000000) => Mon Nov 12 11:56:08 2018 CET(131864937680000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:08 2018 CEST(131813097680000000) => Mon Nov 12 11:56:08 2018 CET(131864937680000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:08 2018 CEST(131813097680000000) => Mon Nov 12 11:56:08 2018 CET(131864937680000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:08 2018 CEST(131813097680000000) => Mon Nov 12 11:56:08 2018 CET(131864937680000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:08 2018 CEST(131813097680000000) => Mon Nov 12 11:56:08 2018 CET(131864937680000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:08 2018 CEST(131813097680000000) => Mon Nov 12 11:56:08 2018 CET(131864937680000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:08 2018 CEST(131813097680000000) => Mon Nov 12 11:56:08 2018 CET(131864937680000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:08 2018 CEST(131813097680000000) => Mon Nov 12 11:56:08 2018 CET(131864937680000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:10 2018 CEST(131813097700000000) => Mon Nov 12 11:56:10 2018 CET(131864937700000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:10 2018 CEST(131813097700000000) => Mon Nov 12 11:56:10 2018 CET(131864937700000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:10 2018 CEST(131813097700000000) => Mon Nov 12 11:56:10 2018 CET(131864937700000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:10 2018 CEST(131813097700000000) => Mon Nov 12 11:56:10 2018 CET(131864937700000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:10 2018 CEST(131813097700000000) => Mon Nov 12 11:56:10 2018 CET(131864937700000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:10 2018 CEST(131813097700000000) => Mon Nov 12 11:56:10 2018 CET(131864937700000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:10 2018 CEST(131813097700000000) => Mon Nov 12 11:56:10 2018 CET(131864937700000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:10 2018 CEST(131813097700000000) => Mon Nov 12 11:56:10 2018 CET(131864937700000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:10 2018 CEST(131813097700000000) => Mon Nov 12 11:56:10 2018 CET(131864937700000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:12 2018 CEST(131813097720000000) => Mon Nov 12 11:56:12 2018 CET(131864937720000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:12 2018 CEST(131813097720000000) => Mon Nov 12 11:56:12 2018 CET(131864937720000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:12 2018 CEST(131813097720000000) => Mon Nov 12 11:56:12 2018 CET(131864937720000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:12 2018 CEST(131813097720000000) => Mon Nov 12 11:56:12 2018 CET(131864937720000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:12 2018 CEST(131813097720000000) => Mon Nov 12 11:56:12 2018 CET(131864937720000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:12 2018 CEST(131813097720000000) => Mon Nov 12 11:56:12 2018 CET(131864937720000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:12 2018 CEST(131813097720000000) => Mon Nov 12 11:56:12 2018 CET(131864937720000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:12 2018 CEST(131813097720000000) => Mon Nov 12 11:56:12 2018 CET(131864937720000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:12 2018 CEST(131813097720000000) => Mon Nov 12 11:56:12 2018 CET(131864937720000000)
> (../source4/torture/smb2/util.c:158) change_time not setup correctly: Thu Sep 13 12:56:14 2018 CEST(131813097740000000) => Mon Nov 12 11:56:14 2018 CET(131864937740000000)
> UNEXPECTED(failure): samba3.smb2.notify.mask(nt4_dc)
> REASON: Exception: Exception: ERROR: nchanges=1 action=2 expectedAction=1 filter=0x00000004
> 
> (and if you have any ideas, this comes up also)
> [100(383)/855 at 5m15s] samba3.blackbox.net_tdb(simpleserver:local)
> UNEXPECTED(failure): samba3.blackbox.net_tdb.Looking for open file in locking.tdb(simpleserver:local)
> REASON: Exception: Exception: Invalid length of key
> 
> (and lastly, this winbind failure, if you happen to have any ideas)
> 
> UNEXPECTED(failure): samba.wbinfo_simple.check-secret.domain=SAMBA-TEST.wbinfo(nt4_member:local)
> REASON: Exception: Exception: wbcCheckTrustCredentials(SAMBA-TEST): error code was NT_STATUS_DOMAIN_CONTROLLER_NOT_FOUND (0xc0000233)
> failed to call wbcCheckTrustCredentials: WBC_ERR_AUTH_ERROR
> Could not check secret
> checking the trust secret for domain SAMBA-TEST via RPC calls failed
> 
> All of the above are from an autobuild on sn-devel over the past couple
> of months, but this has also been seen in Catalyst Cloud builds and on
> GitLab CI.
> 
> For my part, I have an idea how to solve some of the replication tests
> that flap, and plan to put some time into that soon.  Essentially while
> we disable replication, we don't wait for it to stop happening before
> we report success, so we race against a run that hasn't finished.
> 
> Thanks,
> 
> Andrew Bartlett
> 
> -- 
> Andrew Bartlett
> https://samba.org/~abartlet/
> Authentication Developer, Samba Team         https://samba.org
> Samba Development and Support, Catalyst IT   
> https://catalyst.net.nz/services/samba
> 
> 
> 
> 