autobuild[sn-devel-144]: intermittent test failure detected

autobuild autobuild at samba.org
Thu Jun 14 22:52:38 UTC 2018


The autobuild test system (on sn-devel-144) has detected an intermittent failing test in 
the current master tree.

The autobuild log of the failure is available here:

   https://git.samba.org/autobuild.flakey.sn-devel-144/2018-06-15-0052/flakey.log

The failure seems to be in the "samba-ad-dc" suite, whose build logs are available here:

   https://git.samba.org/autobuild.flakey.sn-devel-144/2018-06-15-0052/samba-ad-dc.stderr
   https://git.samba.org/autobuild.flakey.sn-devel-144/2018-06-15-0052/samba-ad-dc.stdout
  
The top commit at the time of the failure was:

commit 5ef6775919e83fdae66385db8d1579fa259602f1
Author: Stefan Metzmacher <metze at samba.org>
Date:   Wed May 23 14:26:37 2018 +0200

    smbd: don't call change_to_root_user() before change_to_guest()
    
    This is just an optimization and it makes it clearer
    that calling change_to_root_user() just before change_to_guest()
    is useless and confusing.
    
    We call change_to_guest() before set_current_service() now,
    but that has no impact as we pass 'do_chdir=false'
    as AS_GUEST is never mixed with AS_USER or DO_CHDIR.
    
    Signed-off-by: Stefan Metzmacher <metze at samba.org>
    Reviewed-by: Jeremy Allison <jra at samba.org>
    
    Autobuild-User(master): Stefan Metzmacher <metze at samba.org>
    Autobuild-Date(master): Thu Jun 14 23:38:55 CEST 2018 on sn-devel-144

and the last 50 lines of the stdout log were:

INFO: Received PING message from server 3003029.2147483652 []
INFO: Received PING message from server 3003029.3799498817 []
{"timestamp": "2018-06-15T00:52:25.070099+0200", "type": "dsdbChange", "dsdbChange": {"attributes": {"lastLogon": {"actions": [{"action": "replace", "values": [{"value": "131734903450680280"}]}]}, "logonCount": {"actions": [{"action": "replace", "values": [{"value": "2"}]}]}}, "version": {"major": 1, "minor": 0}, "status": "Success", "statusCode": 0, "operation": "Modify", "remoteAddress": null, "performedAsSystem": false, "userSid": "S-1-5-18", "dn": "CN=auditlogtestuser02,CN=Users,DC=addom,DC=samba,DC=example,DC=com", "transactionId": "863271e2-a57c-455f-95b6-62a8f6162e08", "sessionId": "9deb0205-738c-4f00-ad20-ed009775e3d1"}}
INFO: Received PING message from server 3003029.195 []
{"timestamp": "2018-06-15T00:52:25.214548+0200", "Authorization": {"authType": "ncacn_np", "domain": "ADDOMAIN", "serviceDescription": "DCE/RPC", "version": {"major": 1, "minor": 1}, "logonServer": "ADDC", "remoteAddress": "ipv4:127.0.0.11:20798", "localAddress": "ipv4:127.0.0.30:445", "account": "auditlogtestuser02", "accountFlags": "0x00000010", "sid": "S-1-5-21-4096988786-662615244-2204655363-1808", "sessionId": "1e5b83c8-a753-4f8a-bf3e-c2093a85e8c7", "transportProtection": "SMB"}, "type": "Authorization"}
INFO: Received PING message from server 3003029.3471000960 []
{"timestamp": "2018-06-15T00:52:25.221230+0200", "type": "dsdbChange", "dsdbChange": {"attributes": {"clearTextPassword": {"actions": [{"action": "replace", "redacted": true}]}}, "version": {"major": 1, "minor": 0}, "status": "insufficient access rights", "statusCode": 50, "operation": "Modify", "remoteAddress": "ipv4:127.0.0.11:20798", "performedAsSystem": false, "userSid": "S-1-5-21-4096988786-662615244-2204655363-1808", "dn": "CN=auditlogtestuser,CN=Users,DC=addom,DC=samba,DC=example,DC=com", "transactionId": "a2189304-ef13-4e28-a4ce-8127b1758e52", "sessionId": "1e5b83c8-a753-4f8a-bf3e-c2093a85e8c7"}}
INFO: Received PING message from server 3003029.3471000960 []
{"timestamp": "2018-06-15T00:52:25.221366+0200", "dsdbTransaction": {"action": "rollback", "version": {"major": 1, "minor": 0}, "transactionId": "a2189304-ef13-4e28-a4ce-8127b1758e52"}, "type": "dsdbTransaction"}
INFO: Received PING message from server 3003029.2147483652 []
INFO: Received PING message from server 3003029.3799498817 []
{"timestamp": "2018-06-15T00:52:25.375530+0200", "type": "dsdbChange", "dsdbChange": {"attributes": {"lastLogon": {"actions": [{"action": "replace", "values": [{"value": "131734903453742590"}]}]}, "logonCount": {"actions": [{"action": "replace", "values": [{"value": "2389"}]}]}}, "version": {"major": 1, "minor": 0}, "status": "Success", "statusCode": 0, "operation": "Modify", "remoteAddress": null, "performedAsSystem": false, "userSid": "S-1-5-18", "dn": "CN=Administrator,CN=Users,DC=addom,DC=samba,DC=example,DC=com", "transactionId": "0af0d208-eef9-4095-83d1-224e0155467c", "sessionId": "9deb0205-738c-4f00-ad20-ed009775e3d1"}}
INFO: Received PING message from server 3003029.2147483652 []
INFO: Received PING message from server 3003029.3799498817 []
{"timestamp": "2018-06-15T00:52:25.393000+0200", "type": "dsdbChange", "dsdbChange": {"attributes": {"lastLogon": {"actions": [{"action": "replace", "values": [{"value": "131734903453917700"}]}]}, "logonCount": {"actions": [{"action": "replace", "values": [{"value": "2390"}]}]}}, "version": {"major": 1, "minor": 0}, "status": "Success", "statusCode": 0, "operation": "Modify", "remoteAddress": null, "performedAsSystem": false, "userSid": "S-1-5-18", "dn": "CN=Administrator,CN=Users,DC=addom,DC=samba,DC=example,DC=com", "transactionId": "2975779b-2387-4b57-a2e4-8906d8375452", "sessionId": "9deb0205-738c-4f00-ad20-ed009775e3d1"}}
INFO: Received PING message from server 3003029.196 []
{"timestamp": "2018-06-15T00:52:25.536529+0200", "Authorization": {"authType": "krb5", "domain": "ADDOMAIN", "serviceDescription": "LDAP", "version": {"major": 1, "minor": 1}, "logonServer": "ADDC", "remoteAddress": "ipv4:127.0.0.11:20805", "localAddress": "ipv4:127.0.0.30:389", "account": "Administrator", "accountFlags": "0x00000010", "sid": "S-1-5-21-4096988786-662615244-2204655363-500", "sessionId": "c176cbc1-25b4-4884-8dac-7928a07437d9", "transportProtection": "SIGN"}, "type": "Authorization"}
INFO: Received PING message from server 3003029.1162914968 []
{"timestamp": "2018-06-15T00:52:25.547786+0200", "type": "dsdbChange", "dsdbChange": {"attributes": {"dSHeuristics": {"actions": [{"action": "replace", "values": [{"value": "000000001"}]}]}}, "version": {"major": 1, "minor": 0}, "status": "Success", "statusCode": 0, "operation": "Modify", "remoteAddress": "ipv4:127.0.0.11:20805", "performedAsSystem": false, "userSid": "S-1-5-21-4096988786-662615244-2204655363-500", "dn": "CN=Directory Service,CN=Windows NT,CN=Services,CN=Configuration,DC=addom,DC=samba,DC=example,DC=com", "transactionId": "c6d14bf5-86da-44ad-bb0f-275de5956e57", "sessionId": "c176cbc1-25b4-4884-8dac-7928a07437d9"}}
INFO: Received PING message from server 3003029.1162914968 []
{"timestamp": "2018-06-15T00:52:25.554201+0200", "type": "dsdbChange", "dsdbChange": {"attributes": {"minPwdAge": {"actions": [{"action": "replace", "values": [{"value": "0"}]}]}}, "version": {"major": 1, "minor": 0}, "status": "Success", "statusCode": 0, "operation": "Modify", "remoteAddress": "ipv4:127.0.0.11:20805", "performedAsSystem": false, "userSid": "S-1-5-21-4096988786-662615244-2204655363-500", "dn": "DC=addom,DC=samba,DC=example,DC=com", "transactionId": "e53f816d-d7b9-40f3-82cb-f408da0e9e96", "sessionId": "c176cbc1-25b4-4884-8dac-7928a07437d9"}}
INFO: Received PING message from server 3003029.1162914968 []
{"timestamp": "2018-06-15T00:52:25.571868+0200", "type": "dsdbChange", "dsdbChange": {"version": {"major": 1, "minor": 0}, "status": "Success", "statusCode": 0, "operation": "Delete", "remoteAddress": "ipv4:127.0.0.11:20805", "performedAsSystem": false, "userSid": "S-1-5-21-4096988786-662615244-2204655363-500", "dn": "cn=auditlogtestuser,cn=users,DC=addom,DC=samba,DC=example,DC=com", "transactionId": "a60d89e4-4e04-45bb-94f0-10daea1a863b", "sessionId": "c176cbc1-25b4-4884-8dac-7928a07437d9"}}
INFO: Received PING message from server 3003029.1162914968 []
{"timestamp": "2018-06-15T00:52:25.590173+0200", "type": "dsdbChange", "dsdbChange": {"version": {"major": 1, "minor": 0}, "status": "Success", "statusCode": 0, "operation": "Delete", "remoteAddress": "ipv4:127.0.0.11:20805", "performedAsSystem": false, "userSid": "S-1-5-21-4096988786-662615244-2204655363-500", "dn": "cn=auditlogtestuser02,cn=users,DC=addom,DC=samba,DC=example,DC=com", "transactionId": "6fb070a6-1744-41e6-afb6-e37eed066ba8", "sessionId": "c176cbc1-25b4-4884-8dac-7928a07437d9"}}
INFO: Received PING message from server 3003029.1162914968 []
{"timestamp": "2018-06-15T00:52:25.750816+0200", "type": "dsdbChange", "dsdbChange": {"attributes": {"sAMAccountName": {"actions": [{"action": "add", "values": [{"value": "auditlogtestuser"}]}]}, "objectclass": {"actions": [{"action": "add", "values": [{"value": "user"}]}]}, "userPassword": {"actions": [{"action": "add", "redacted": true}]}}, "version": {"major": 1, "minor": 0}, "status": "Success", "statusCode": 0, "operation": "Add", "remoteAddress": "ipv4:127.0.0.11:20805", "performedAsSystem": false, "userSid": "S-1-5-21-4096988786-662615244-2204655363-500", "dn": "cn=auditlogtestuser,cn=users,DC=addom,DC=samba,DC=example,DC=com", "transactionId": "003dc772-e503-4b06-9e9a-1fcc684a7166", "sessionId": "c176cbc1-25b4-4884-8dac-7928a07437d9"}}
Received 2 messages
UNEXPECTED(failure): samba.tests.audit_log_dsdb.samba.tests.audit_log_dsdb.AuditLogDsdbTests.test_samdb_delete_user(ad_dc:local)
REASON: Exception: Exception: Traceback (most recent call last):
  File "bin/python/samba/tests/audit_log_dsdb.py", line 339, in test_samdb_delete_user
    self.assertEquals("Delete", audit["operation"])
AssertionError: 'Delete' != u'Add'

FAILED (1 failures, 0 errors and 0 unexpected successes in 0 testsuites)

A summary with detailed information can be found in:
  ./bin/ab/summary
TOP 10 slowest tests
samba3.local.nss(ad_dc:local) -> 152
samba.tests.samba_tool.user(ad_dc:local) -> 67
samba3.rpc.samr.passwords.pwdlastset(ad_dc) -> 56
samba3.raw.session krb5(ad_dc) -> 53
samba3.rpc.schannel(ad_dc) -> 49
samba3.rpc.spoolss.printer(ad_dc) -> 47
samba4.blackbox.net_ads(ad_dc:client)(ad_dc:client) -> 41
samba3.smb2.session krb5(ad_dc) -> 39
samba4.rpc.schannel with bigendian(ad_dc) -> 37
samba3.smb2.dir(ad_dc) -> 37
ERROR: test failed with exit code 1



More information about the samba-cvs mailing list