You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2020/09/01 05:06:15 UTC

Build failed in Jenkins: Mesos » Mesos-Reviewbot-Linux #250

See <https://ci-builds.apache.org/job/Mesos/job/Mesos-Reviewbot-Linux/250/display/redirect?page=changes>

Changes:

[zhq527725] Enabled CSI volume access for non-root users.

[zhq527725] Relaxed unknown volume check when unpublishing volumes.


------------------------------------------
[...truncated 13.66 MB...]
I0901 04:12:51.331288  5521 slave.cpp:1538] Detecting new master
I0901 04:12:51.332841  5515 slave.cpp:1565] Authenticating with master master@172.17.0.2:33863
I0901 04:12:51.332996  5515 slave.cpp:1574] Using default CRAM-MD5 authenticatee
I0901 04:12:51.333407  5523 authenticatee.cpp:121] Creating new client SASL connection
I0901 04:12:51.333806  5515 master.cpp:9727] Authenticating slave(129)@172.17.0.2:33863
I0901 04:12:51.334026  5516 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(277)@172.17.0.2:33863
I0901 04:12:51.334517  5520 authenticator.cpp:98] Creating new server SASL connection
I0901 04:12:51.334913  5525 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0901 04:12:51.334949  5525 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0901 04:12:51.335079  5525 authenticator.cpp:204] Received SASL authentication start
I0901 04:12:51.335150  5525 authenticator.cpp:326] Authentication requires more steps
I0901 04:12:51.335269  5525 authenticatee.cpp:259] Received SASL authentication step
I0901 04:12:51.335400  5525 authenticator.cpp:232] Received SASL authentication step
I0901 04:12:51.335435  5525 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2e7f058cc395' server FQDN: '2e7f058cc395' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0901 04:12:51.335451  5525 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0901 04:12:51.335496  5525 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0901 04:12:51.335525  5525 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2e7f058cc395' server FQDN: '2e7f058cc395' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0901 04:12:51.335541  5525 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0901 04:12:51.335551  5525 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0901 04:12:51.335569  5525 authenticator.cpp:318] Authentication success
I0901 04:12:51.335673  5509 authenticatee.cpp:299] Authentication success
I0901 04:12:51.335762  5526 master.cpp:9759] Successfully authenticated principal 'test-principal' at slave(129)@172.17.0.2:33863
I0901 04:12:51.335803  5517 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(277)@172.17.0.2:33863
I0901 04:12:51.336228  5525 slave.cpp:1665] Successfully authenticated with master master@172.17.0.2:33863
I0901 04:12:51.336650  5525 slave.cpp:2131] Will retry registration in 13.595082ms if necessary
I0901 04:12:51.336830  5518 master.cpp:6221] Received register agent message from slave(129)@172.17.0.2:33863 (2e7f058cc395)
I0901 04:12:51.337237  5518 master.cpp:3752] Authorizing principal 'test-principal' to perform action REGISTER_AGENT on ANY object
I0901 04:12:51.337787  5513 master.cpp:6288] Authorized registration of agent at slave(129)@172.17.0.2:33863 (2e7f058cc395)
I0901 04:12:51.337904  5513 master.cpp:6400] Registering agent at slave(129)@172.17.0.2:33863 (2e7f058cc395) with id e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S7
I0901 04:12:51.338778  5521 registrar.cpp:487] Applied 1 operations in 407707ns; attempting to update the registry
I0901 04:12:51.339694  5523 registrar.cpp:544] Successfully updated the registry in 0ns
I0901 04:12:51.339892  5516 master.cpp:6448] Admitted agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S7 at slave(129)@172.17.0.2:33863 (2e7f058cc395)
I0901 04:12:51.340626  5516 master.cpp:6493] Registered agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S7 at slave(129)@172.17.0.2:33863 (2e7f058cc395) with cpus:1; mem:10; disk:10; ports:[1-10]
I0901 04:12:51.340788  5522 hierarchical.cpp:1041] Added agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S7 (2e7f058cc395) with cpus:1; mem:10; disk:10; ports:[1-10] (offered or allocated: {})
I0901 04:12:51.340821  5527 slave.cpp:1698] Registered with master master@172.17.0.2:33863; given agent ID e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S7
I0901 04:12:51.340981  5519 task_status_update_manager.cpp:188] Resuming sending task status updates
I0901 04:12:51.341177  5522 hierarchical.cpp:1935] Performed allocation for 1 agents in 143869ns
I0901 04:12:51.341253  5527 slave.cpp:1733] Checkpointing SlaveInfo to '/tmp/MasterAllocatorTest_0_MinAllocatableResources_5AFQ0o/meta/slaves/e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S7/slave.info'
I0901 04:12:51.341293  5522 status_update_manager_process.hpp:385] Resuming operation status update manager
I0901 04:12:51.342480  5527 slave.cpp:1793] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"HAJhPuCqQ6CuJBl95YnNGQ=="},"slave_id":{"value":"e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S7"},"update_oversubscribed_resources":false}
I0901 04:12:51.343262  5527 master.cpp:7635] Ignoring update on agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S7 at slave(129)@172.17.0.2:33863 (2e7f058cc395) as it reports no changes
W0901 04:12:51.512737  5505 process.cpp:2877] Attempted to spawn already running process version@172.17.0.2:33863
I0901 04:12:51.513849  5505 sched.cpp:239] Version: 1.11.0
I0901 04:12:51.514590  5508 sched.cpp:343] New master detected at master@172.17.0.2:33863
I0901 04:12:51.514712  5508 sched.cpp:408] Authenticating with master master@172.17.0.2:33863
I0901 04:12:51.514734  5508 sched.cpp:415] Using default CRAM-MD5 authenticatee
I0901 04:12:51.515045  5515 authenticatee.cpp:121] Creating new client SASL connection
I0901 04:12:51.515352  5508 master.cpp:9727] Authenticating scheduler-6f3e84f0-6c4c-4220-b098-306c0c94bd53@172.17.0.2:33863
I0901 04:12:51.515507  5516 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(278)@172.17.0.2:33863
I0901 04:12:51.515825  5524 authenticator.cpp:98] Creating new server SASL connection
I0901 04:12:51.516068  5519 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0901 04:12:51.516103  5519 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0901 04:12:51.516224  5519 authenticator.cpp:204] Received SASL authentication start
I0901 04:12:51.516284  5519 authenticator.cpp:326] Authentication requires more steps
I0901 04:12:51.516398  5519 authenticatee.cpp:259] Received SASL authentication step
I0901 04:12:51.516546  5526 authenticator.cpp:232] Received SASL authentication step
I0901 04:12:51.516592  5526 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2e7f058cc395' server FQDN: '2e7f058cc395' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0901 04:12:51.516618  5526 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0901 04:12:51.516670  5526 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0901 04:12:51.516711  5526 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2e7f058cc395' server FQDN: '2e7f058cc395' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0901 04:12:51.516732  5526 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0901 04:12:51.516757  5526 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0901 04:12:51.516790  5526 authenticator.cpp:318] Authentication success
I0901 04:12:51.516903  5509 authenticatee.cpp:299] Authentication success
I0901 04:12:51.516980  5517 master.cpp:9759] Successfully authenticated principal 'test-principal' at scheduler-6f3e84f0-6c4c-4220-b098-306c0c94bd53@172.17.0.2:33863
I0901 04:12:51.517119  5525 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(278)@172.17.0.2:33863
I0901 04:12:51.517346  5526 sched.cpp:520] Successfully authenticated with master master@172.17.0.2:33863
I0901 04:12:51.517383  5526 sched.cpp:835] Sending SUBSCRIBE call to master@172.17.0.2:33863
I0901 04:12:51.517585  5526 sched.cpp:870] Will retry registration in 355.826088ms if necessary
I0901 04:12:51.517792  5518 master.cpp:2941] Received SUBSCRIBE call for framework 'default' at scheduler-6f3e84f0-6c4c-4220-b098-306c0c94bd53@172.17.0.2:33863
I0901 04:12:51.521178  5513 master.cpp:3024] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0901 04:12:51.525583  5513 master.cpp:9958] Adding framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000 (default) at scheduler-6f3e84f0-6c4c-4220-b098-306c0c94bd53@172.17.0.2:33863 with roles {  } suppressed
I0901 04:12:51.526636  5508 sched.cpp:751] Framework registered with e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000
I0901 04:12:51.526701  5508 sched.cpp:770] Scheduler::registered took 26242ns
I0901 04:12:51.526988  5523 hierarchical.cpp:774] Added framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000
I0901 04:12:51.530483  5523 hierarchical.cpp:1935] Performed allocation for 8 agents in 3.277356ms
I0901 04:12:51.532150  5524 master.cpp:9536] Sending offers [ e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-O0, e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-O1, e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-O2, e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-O3 ] to framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000 (default) at scheduler-6f3e84f0-6c4c-4220-b098-306c0c94bd53@172.17.0.2:33863
I0901 04:12:51.533186  5528 sched.cpp:934] Scheduler::resourceOffers took 119480ns
I0901 04:12:51.533318  5505 sched.cpp:2166] Asked to stop the driver
I0901 04:12:51.533453  5522 sched.cpp:1204] Stopping framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000
I0901 04:12:51.533746  5519 master.cpp:10323] Processing TEARDOWN call for framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000 (default) at scheduler-6f3e84f0-6c4c-4220-b098-306c0c94bd53@172.17.0.2:33863
I0901 04:12:51.533788  5519 master.cpp:10335] Removing framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000 (default) at scheduler-6f3e84f0-6c4c-4220-b098-306c0c94bd53@172.17.0.2:33863
I0901 04:12:51.533810  5519 master.cpp:3385] Deactivating framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000 (default) at scheduler-6f3e84f0-6c4c-4220-b098-306c0c94bd53@172.17.0.2:33863
I0901 04:12:51.533975  5517 hierarchical.cpp:887] Deactivated framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000
I0901 04:12:51.534595  5519 master.cpp:11834] Removing offer e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-O3
I0901 04:12:51.534677  5505 slave.cpp:1002] Agent terminating
I0901 04:12:51.534899  5529 hierarchical.cpp:1658] Recovered ports(allocated: *):[1-5]; cpus(allocated: *):0.5; mem(allocated: *):10; disk(allocated: *):100 (total: cpus:0.5; mem:10; disk:100; ports:[1-5], offered or allocated: {}) on agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S5 from framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000
I0901 04:12:51.535213  5519 master.cpp:11834] Removing offer e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-O1
I0901 04:12:51.535761  5519 master.cpp:11834] Removing offer e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-O2
I0901 04:12:51.536203  5519 master.cpp:11834] Removing offer e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-O0
I0901 04:12:51.536448  5509 slave.cpp:4285] Asked to shut down framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000 by master@172.17.0.2:33863
I0901 04:12:51.536470  5510 slave.cpp:4285] Asked to shut down framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000 by master@172.17.0.2:33863
I0901 04:12:51.536502  5509 slave.cpp:4300] Cannot shut down unknown framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000
I0901 04:12:51.536512  5510 slave.cpp:4300] Cannot shut down unknown framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000
I0901 04:12:51.536502  5517 slave.cpp:4285] Asked to shut down framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000 by master@172.17.0.2:33863
I0901 04:12:51.536573  5517 slave.cpp:4300] Cannot shut down unknown framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000
I0901 04:12:51.536588  5525 slave.cpp:4285] Asked to shut down framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000 by master@172.17.0.2:33863
I0901 04:12:51.536625  5525 slave.cpp:4300] Cannot shut down unknown framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000
I0901 04:12:51.536653  5507 slave.cpp:4285] Asked to shut down framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000 by master@172.17.0.2:33863
I0901 04:12:51.536698  5507 slave.cpp:4300] Cannot shut down unknown framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000
I0901 04:12:51.536752  5511 slave.cpp:4285] Asked to shut down framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000 by master@172.17.0.2:33863
I0901 04:12:51.536798  5511 slave.cpp:4300] Cannot shut down unknown framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000
I0901 04:12:51.536792  5526 slave.cpp:4285] Asked to shut down framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000 by master@172.17.0.2:33863
I0901 04:12:51.536828  5526 slave.cpp:4300] Cannot shut down unknown framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000
I0901 04:12:51.537189  5519 master.cpp:1297] Agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S0 at slave(122)@172.17.0.2:33863 (2e7f058cc395) disconnected
I0901 04:12:51.537217  5519 master.cpp:3420] Disconnecting agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S0 at slave(122)@172.17.0.2:33863 (2e7f058cc395)
I0901 04:12:51.537286  5519 master.cpp:3439] Deactivating agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S0 at slave(122)@172.17.0.2:33863 (2e7f058cc395)
I0901 04:12:51.537250  5529 hierarchical.cpp:1658] Recovered ports(allocated: *):[31000-32000]; cpus(allocated: *):1; mem(allocated: *):100; disk(allocated: *):50 (total: cpus:1; mem:100; disk:50; ports:[31000-32000], offered or allocated: {}) on agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S6 from framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000
I0901 04:12:51.539513  5529 hierarchical.cpp:1658] Recovered ports(allocated: *):[1-10]; cpus(allocated: *):1; mem(allocated: *):10; disk(allocated: *):10 (total: cpus:1; mem:10; disk:10; ports:[1-10], offered or allocated: {}) on agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S7 from framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000
I0901 04:12:51.541687  5529 hierarchical.cpp:1658] Recovered ports(allocated: *):[1-5]; cpus(allocated: *):1; mem(allocated: *):100 (total: cpus:1; mem:100; ports:[1-5], offered or allocated: {}) on agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S4 from framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000
I0901 04:12:51.543301  5529 hierarchical.cpp:1859] Allocation paused
I0901 04:12:51.544092  5529 hierarchical.cpp:831] Removed framework e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-0000
I0901 04:12:51.544195  5529 hierarchical.cpp:1869] Allocation resumed
I0901 04:12:51.544277  5529 hierarchical.cpp:1238] Agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S0 deactivated
I0901 04:12:51.547294  5515 hierarchical.cpp:1935] Performed allocation for 8 agents in 495212ns
I0901 04:12:51.556768  5505 slave.cpp:1002] Agent terminating
I0901 04:12:51.557585  5528 master.cpp:1297] Agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S1 at slave(123)@172.17.0.2:33863 (2e7f058cc395) disconnected
I0901 04:12:51.557624  5528 master.cpp:3420] Disconnecting agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S1 at slave(123)@172.17.0.2:33863 (2e7f058cc395)
I0901 04:12:51.557693  5528 master.cpp:3439] Deactivating agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S1 at slave(123)@172.17.0.2:33863 (2e7f058cc395)
I0901 04:12:51.557860  5508 hierarchical.cpp:1238] Agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S1 deactivated
I0901 04:12:51.567517  5505 slave.cpp:1002] Agent terminating
I0901 04:12:51.568562  5513 master.cpp:1297] Agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S2 at slave(124)@172.17.0.2:33863 (2e7f058cc395) disconnected
I0901 04:12:51.568622  5513 master.cpp:3420] Disconnecting agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S2 at slave(124)@172.17.0.2:33863 (2e7f058cc395)
I0901 04:12:51.568758  5513 master.cpp:3439] Deactivating agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S2 at slave(124)@172.17.0.2:33863 (2e7f058cc395)
I0901 04:12:51.569154  5518 hierarchical.cpp:1238] Agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S2 deactivated
I0901 04:12:51.576655  5505 slave.cpp:1002] Agent terminating
I0901 04:12:51.577474  5508 master.cpp:1297] Agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S3 at slave(125)@172.17.0.2:33863 (2e7f058cc395) disconnected
I0901 04:12:51.577510  5508 master.cpp:3420] Disconnecting agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S3 at slave(125)@172.17.0.2:33863 (2e7f058cc395)
I0901 04:12:51.577581  5508 master.cpp:3439] Deactivating agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S3 at slave(125)@172.17.0.2:33863 (2e7f058cc395)
I0901 04:12:51.577814  5529 hierarchical.cpp:1238] Agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S3 deactivated
I0901 04:12:51.585512  5505 slave.cpp:1002] Agent terminating
I0901 04:12:51.586246  5512 master.cpp:1297] Agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S4 at slave(126)@172.17.0.2:33863 (2e7f058cc395) disconnected
I0901 04:12:51.586308  5512 master.cpp:3420] Disconnecting agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S4 at slave(126)@172.17.0.2:33863 (2e7f058cc395)
I0901 04:12:51.586462  5512 master.cpp:3439] Deactivating agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S4 at slave(126)@172.17.0.2:33863 (2e7f058cc395)
I0901 04:12:51.586673  5514 hierarchical.cpp:1238] Agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S4 deactivated
I0901 04:12:51.597558  5507 slave.cpp:1002] Agent terminating
I0901 04:12:51.598603  5508 master.cpp:1297] Agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S5 at slave(127)@172.17.0.2:33863 (2e7f058cc395) disconnected
I0901 04:12:51.598654  5508 master.cpp:3420] Disconnecting agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S5 at slave(127)@172.17.0.2:33863 (2e7f058cc395)
I0901 04:12:51.598753  5508 master.cpp:3439] Deactivating agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S5 at slave(127)@172.17.0.2:33863 (2e7f058cc395)
I0901 04:12:51.598929  5528 hierarchical.cpp:1238] Agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S5 deactivated
I0901 04:12:51.609072  5505 slave.cpp:1002] Agent terminating
I0901 04:12:51.609846  5515 master.cpp:1297] Agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S6 at slave(128)@172.17.0.2:33863 (2e7f058cc395) disconnected
I0901 04:12:51.609920  5515 master.cpp:3420] Disconnecting agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S6 at slave(128)@172.17.0.2:33863 (2e7f058cc395)
I0901 04:12:51.610082  5515 master.cpp:3439] Deactivating agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S6 at slave(128)@172.17.0.2:33863 (2e7f058cc395)
I0901 04:12:51.610379  5520 hierarchical.cpp:1238] Agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S6 deactivated
I0901 04:12:51.619027  5510 slave.cpp:1002] Agent terminating
I0901 04:12:51.620076  5528 master.cpp:1297] Agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S7 at slave(129)@172.17.0.2:33863 (2e7f058cc395) disconnected
I0901 04:12:51.620118  5528 master.cpp:3420] Disconnecting agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S7 at slave(129)@172.17.0.2:33863 (2e7f058cc395)
I0901 04:12:51.620214  5528 master.cpp:3439] Deactivating agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S7 at slave(129)@172.17.0.2:33863 (2e7f058cc395)
I0901 04:12:51.620460  5520 hierarchical.cpp:1238] Agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S7 deactivated
I0901 04:12:51.629426  5505 master.cpp:1145] Master terminating
I0901 04:12:51.629894  5511 hierarchical.cpp:1214] Removed all filters for agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S5
I0901 04:12:51.629940  5511 hierarchical.cpp:1090] Removed agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S5
I0901 04:12:51.630285  5522 hierarchical.cpp:1214] Removed all filters for agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S6
I0901 04:12:51.630313  5522 hierarchical.cpp:1090] Removed agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S6
I0901 04:12:51.630550  5522 hierarchical.cpp:1214] Removed all filters for agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S0
I0901 04:12:51.630575  5522 hierarchical.cpp:1090] Removed agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S0
I0901 04:12:51.630807  5528 hierarchical.cpp:1214] Removed all filters for agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S3
I0901 04:12:51.630839  5528 hierarchical.cpp:1090] Removed agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S3
I0901 04:12:51.631152  5520 hierarchical.cpp:1214] Removed all filters for agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S7
I0901 04:12:51.631201  5520 hierarchical.cpp:1090] Removed agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S7
I0901 04:12:51.631441  5520 hierarchical.cpp:1214] Removed all filters for agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S4
I0901 04:12:51.631476  5520 hierarchical.cpp:1090] Removed agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S4
I0901 04:12:51.631736  5520 hierarchical.cpp:1214] Removed all filters for agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S1
I0901 04:12:51.631783  5520 hierarchical.cpp:1090] Removed agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S1
I0901 04:12:51.632052  5520 hierarchical.cpp:1214] Removed all filters for agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S2
I0901 04:12:51.632091  5520 hierarchical.cpp:1090] Removed agent e9ff7454-bfb0-40bc-b4a5-9033fd7eeda9-S2
[       OK ] MasterAllocatorTest/0.MinAllocatableResources (1745 ms)
[ RUN      ] MasterAllocatorTest/0.Whitelist
I0901 04:12:51.650084  5505 cluster.cpp:195] Creating default 'local' authorizer
I0901 04:12:51.655222  5529 master.cpp:448] Master 831292e6-98d0-4bb0-8ae0-e9bd1ac41f58 (2e7f058cc395) started on 172.17.0.2:33863
I0901 04:12:51.655272  5529 master.cpp:451] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/g7RqN2/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_operator_event_stream_subscribers="1000" --max_unreachable_tasks_per_framework="1000" --memory_profiling="false" --min_allocatable_resources="cpus:0.01|mem:32" --offer_constraints_re2_max_mem="4KB" --offer_constraints_re2_max_program_size="100" --port="5050" --publish_per_framework_metrics="true" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --require_agent_domain="false" --role_sorter="drf" --root_submissions="true" --version="false" --webui_dir="/tmp/SRC/build/mesos-1.11.0/_inst/share/mesos/webui" --whitelist="whitelist.txt" --work_dir="/tmp/g7RqN2/master" --zk_session_timeout="10secs"
I0901 04:12:51.655999  5529 master.cpp:500] Master only allowing authenticated frameworks to register
I0901 04:12:51.656029  5529 master.cpp:506] Master only allowing authenticated agents to register
I0901 04:12:51.656049  5529 master.cpp:512] Master only allowing authenticated HTTP frameworks to register
I0901 04:12:51.656069  5529 credentials.hpp:37] Loading credentials for authentication from '/tmp/g7RqN2/credentials'
I0901 04:12:51.656561  5529 master.cpp:556] Using default 'crammd5' authenticator
I0901 04:12:51.656929  5529 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0901 04:12:51.657325  5529 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0901 04:12:51.657652  5529 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheBuild timed out (after 240 minutes). Marking the build as failed.
duler'
I0901 04:12:51.657963  5529 master.cpp:637] Authorization enabled
I0901 04:12:51.658560  5526 hierarchical.cpp:637] Initialized hierarchical allocator process
I0901 04:12:51.659133  5527 hierarchical.cpp:1250] Updated agent whitelist: { dummy-agent1 }
I0901 04:12:51.664510  5519 master.cpp:2170] Elected as the leading master!
I0901 04:12:51.664549  5519 master.cpp:1666] Recovering from registrar
I0901 04:12:51.664744  5525 registrar.cpp:339] Recovering registrar
I0901 04:12:51.665488  5525 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns
I0901 04:12:51.665647  5525 registrar.cpp:487] Applied 1 operations in 56188ns; attempting to update the registry
I0901 04:12:51.666604  5522 registrar.cpp:544] Successfully updated the registry in 0ns
I0901 04:12:51.666779  5522 registrar.cpp:416] Successfully recovered registrar
I0901 04:12:51.667337  5523 hierarchical.cpp:676] Skipping recovery of hierarchical allocator: nothing to recover
I0901 04:12:51.667389  5524 master.cpp:1819] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister
I0901 04:12:51.670266  5528 hierarchical.cpp:1935] Performed allocation for 0 agents in 64978ns
I0901 04:12:51.671088  5527 hierarchical.cpp:1250] Updated agent whitelist: { dummy-agent1, dummy-agent2 }
I0901 04:12:51.671291  5505 master.cpp:1145] Master terminating
[       OK ] MasterAllocatorTest/0.Whitelist (30 ms)
[ RUN      ] MasterAllocatorTest/0.RoleTest
I0901 04:12:51.680305  5505 cluster.cpp:195] Creating default 'local' authorizer
I0901 04:12:51.684489  5514 master.cpp:448] Master 6497a3f9-aaf2-49c1-b846-fba01d0e8466 (2e7f058cc395) started on 172.17.0.2:33863
I0901 04:12:51.684521  5514 master.cpp:451] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/LeWgEM/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_operator_event_stream_subscribers="1000" --max_unreachable_tasks_per_framework="1000" --memory_profiling="false" --min_allocatable_resources="cpus:0.01|mem:32" --offer_constraints_re2_max_mem="4KB" --offer_constraints_re2_max_program_size="100" --port="5050" --publish_per_framework_metrics="true" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --require_agent_domain="false" --role_sorter="drf" --roles="role2" --root_submissions="true" --version="false" --webui_dir="/tmp/SRC/build/mesos-1.11.0/_inst/share/mesos/webui" --work_dir="/tmp/LeWgEM/master" --zk_session_timeout="10secs"
I0901 04:12:51.684876  5514 master.cpp:500] Master only allowing authenticated frameworks to register
I0901 04:12:51.684890  5514 master.cpp:506] Master only allowing authenticated agents to register
I0901 04:12:51.684900  5514 master.cpp:512] Master only allowing authenticated HTTP frameworks to register
I0901 04:12:51.684908  5514 credentials.hpp:37] Loading credentials for authentication from '/tmp/LeWgEM/credentials'
I0901 04:12:51.685159  5514 master.cpp:556] Using default 'crammd5' authenticator
I0901 04:12:51.685339  5514 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0901 04:12:51.685523  5514 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0901 04:12:51.685680  5514 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0901 04:12:51.685830  5514 master.cpp:637] Authorization enabled
W0901 04:12:51.685850  5514 master.cpp:700] The '--roles' flag is deprecated. This flag will be removed in the future. See the Mesos 0.27 upgrade notes for more information
I0901 04:12:51.686223  5526 hierarchical.cpp:637] Initialized hierarchical allocator process
I0901 04:12:51.686265  5516 whitelist_watcher.cpp:77] No whitelist given
I0901 04:12:51.689477  5520 master.cpp:2170] Elected as the leading master!
I0901 04:12:51.689543  5520 master.cpp:1666] Recovering from registrar
I0901 04:12:51.689940  5512 registrar.cpp:339] Recovering registrar
I0901 04:12:51.691177  5512 registrar.cpp:383] Successfully fetched the registry (0B) in 1.157888ms
I0901 04:12:51.691416  5512 registrar.cpp:487] Applied 1 operations in 66213ns; attempting to update the registry
I0901 04:12:51.692395  5512 registrar.cpp:544] Successfully updated the registry in 882176ns
I0901 04:12:51.692698  5512 registrar.cpp:416] Successfully recovered registrar
I0901 04:12:51.693384  5510 master.cpp:1819] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister
I0901 04:12:51.693408  5508 hierarchical.cpp:676] Skipping recovery of hierarchical allocator: nothing to recover
W0901 04:12:51.695936  5505 process.cpp:2877] Attempted to spawn already running process version@172.17.0.2:33863
I0901 04:12:51.696977  5505 sched.cpp:239] Version: 1.11.0
I0901 04:12:51.697715  5514 sched.cpp:343] New master detected at master@172.17.0.2:33863
I0901 04:12:51.697866  5514 sched.cpp:408] Authenticating with master master@172.17.0.2:33863
I0901 04:12:51.697894  5514 sched.cpp:415] Using default CRAM-MD5 authenticatee
I0901 04:12:51.698297  5517 authenticatee.cpp:121] Creating new client SASL connection
I0901 04:12:51.698815  5513 master.cpp:9727] Authenticating scheduler-d54e9f2c-5a97-45c2-bb48-c27ce279c1f6@172.17.0.2:33863
I0901 04:12:51.699084  5525 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(279)@172.17.0.2:33863
I0901 04:12:51.699523  5506 authenticator.cpp:98] Creating new server SASL connection
I0901 04:12:51.699923  5511 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0901 04:12:51.699992  5511 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0901 04:12:51.700203  5511 authenticator.cpp:204] Received SASL authentication start
I0901 04:12:51.700325  5511 authenticator.cpp:326] Authentication requires more steps
I0901 04:12:51.700521  5511 authenticatee.cpp:259] Received SASL authentication step
I0901 04:12:51.700711  5511 authenticator.cpp:232] Received SASL authentication step
I0901 04:12:51.700764  5511 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2e7f058cc395' server FQDN: '2e7f058cc395' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0901 04:12:51.700789  5511 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0901 04:12:51.700868  5511 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0901 04:12:51.700920  5511 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2e7f058cc395' server FQDN: '2e7f058cc395' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0901 04:12:51.700944  5511 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0901 04:12:51.700963  5511 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0901 04:12:51.700996  5511 authenticator.cpp:318] Authentication success
I0901 04:12:51.701155  5522 authenticatee.cpp:299] Authentication success
I0901 04:12:51.701333  5510 master.cpp:9759] Successfully authenticated principal 'test-principal' at scheduler-d54e9f2c-5a97-45c2-bb48-c27ce279c1f6@172.17.0.2:33863
I0901 04:12:51.701350  5528 authenticator.cBuild was aborted
pp:432] Authentication session cleanup for crammd5-authenticatee(279)@172.17.0.2:33863
I0901 04:12:51.701733  5523 sched.cpp:520] Successfully authenticated with master master@172.17.0.2:33863

Jenkins build is back to normal : Mesos » Mesos-Reviewbot-Linux #252

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://ci-builds.apache.org/job/Mesos/job/Mesos-Reviewbot-Linux/252/display/redirect>


Build failed in Jenkins: Mesos » Mesos-Reviewbot-Linux #251

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://ci-builds.apache.org/job/Mesos/job/Mesos-Reviewbot-Linux/251/display/redirect>

Changes:


------------------------------------------
[...truncated 13.44 MB...]
I0901 08:17:40.452705  5527 slave.cpp:637] Agent attributes: [  ]
I0901 08:17:40.452718  5527 slave.cpp:646] Agent hostname: 0f73b3326edc
I0901 08:17:40.453037  5524 status_update_manager_process.hpp:379] Pausing operation status update manager
I0901 08:17:40.453060  5523 task_status_update_manager.cpp:181] Pausing sending task status updates
I0901 08:17:40.454382  5515 state.cpp:68] Recovering state from '/tmp/MasterAllocatorTest_0_SlaveLost_cpbrRU/meta'
I0901 08:17:40.454814  5525 slave.cpp:7741] Finished recovering checkpointed state from '/tmp/MasterAllocatorTest_0_SlaveLost_cpbrRU/meta', beginning agent recovery
I0901 08:17:40.455665  5520 task_status_update_manager.cpp:207] Recovering task status update manager
I0901 08:17:40.456362  5528 containerizer.cpp:830] Recovering Mesos containers
I0901 08:17:40.456758  5528 containerizer.cpp:1170] Recovering isolators
I0901 08:17:40.457690  5518 containerizer.cpp:1209] Recovering provisioner
I0901 08:17:40.458956  5519 provisioner.cpp:518] Provisioner recovery complete
I0901 08:17:40.459820  5527 composing.cpp:343] Finished recovering all containerizers
I0901 08:17:40.460089  5511 slave.cpp:8223] Recovering executors
I0901 08:17:40.460198  5511 slave.cpp:8376] Finished recovery
I0901 08:17:40.461585  5522 task_status_update_manager.cpp:181] Pausing sending task status updates
I0901 08:17:40.461628  5521 status_update_manager_process.hpp:379] Pausing operation status update manager
I0901 08:17:40.461601  5511 slave.cpp:1473] New master detected at master@172.17.0.3:34493
I0901 08:17:40.461843  5511 slave.cpp:1538] Detecting new master
I0901 08:17:40.466346  5532 slave.cpp:1565] Authenticating with master master@172.17.0.3:34493
I0901 08:17:40.466532  5532 slave.cpp:1574] Using default CRAM-MD5 authenticatee
I0901 08:17:40.466922  5528 authenticatee.cpp:121] Creating new client SASL connection
I0901 08:17:40.467291  5523 master.cpp:9727] Authenticating slave(117)@172.17.0.3:34493
I0901 08:17:40.467558  5518 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(264)@172.17.0.3:34493
I0901 08:17:40.468091  5531 authenticator.cpp:98] Creating new server SASL connection
I0901 08:17:40.468533  5524 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0901 08:17:40.468592  5524 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0901 08:17:40.468780  5524 authenticator.cpp:204] Received SASL authentication start
I0901 08:17:40.468889  5524 authenticator.cpp:326] Authentication requires more steps
I0901 08:17:40.469058  5524 authenticatee.cpp:259] Received SASL authentication step
I0901 08:17:40.469246  5524 authenticator.cpp:232] Received SASL authentication step
I0901 08:17:40.469297  5524 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '0f73b3326edc' server FQDN: '0f73b3326edc' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0901 08:17:40.469324  5524 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0901 08:17:40.469395  5524 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0901 08:17:40.469439  5524 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '0f73b3326edc' server FQDN: '0f73b3326edc' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0901 08:17:40.469462  5524 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0901 08:17:40.469482  5524 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0901 08:17:40.469511  5524 authenticator.cpp:318] Authentication success
I0901 08:17:40.469703  5515 authenticatee.cpp:299] Authentication success
I0901 08:17:40.469863  5525 master.cpp:9759] Successfully authenticated principal 'test-principal' at slave(117)@172.17.0.3:34493
I0901 08:17:40.469877  5514 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(264)@172.17.0.3:34493
I0901 08:17:40.470511  5516 slave.cpp:1665] Successfully authenticated with master master@172.17.0.3:34493
I0901 08:17:40.471284  5516 slave.cpp:2131] Will retry registration in 17.00382ms if necessary
I0901 08:17:40.471475  5533 master.cpp:6221] Received register agent message from slave(117)@172.17.0.3:34493 (0f73b3326edc)
I0901 08:17:40.471907  5533 master.cpp:3752] Authorizing principal 'test-principal' to perform action REGISTER_AGENT on ANY object
I0901 08:17:40.472517  5521 master.cpp:6288] Authorized registration of agent at slave(117)@172.17.0.3:34493 (0f73b3326edc)
I0901 08:17:40.472692  5521 master.cpp:6400] Registering agent at slave(117)@172.17.0.3:34493 (0f73b3326edc) with id a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-S1
I0901 08:17:40.473467  5513 registrar.cpp:487] Applied 1 operations in 280295ns; attempting to update the registry
I0901 08:17:40.474102  5513 registrar.cpp:544] Successfully updated the registry in 557056ns
I0901 08:17:40.474330  5513 master.cpp:6448] Admitted agent a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-S1 at slave(117)@172.17.0.3:34493 (0f73b3326edc)
I0901 08:17:40.475019  5513 master.cpp:6493] Registered agent a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-S1 at slave(117)@172.17.0.3:34493 (0f73b3326edc) with cpus:3; mem:256; disk:1024; ports:[31000-32000]
I0901 08:17:40.475414  5529 hierarchical.cpp:1041] Added agent a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-S1 (0f73b3326edc) with cpus:3; mem:256; disk:1024; ports:[31000-32000] (offered or allocated: {})
I0901 08:17:40.475473  5519 slave.cpp:1698] Registered with master master@172.17.0.3:34493; given agent ID a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-S1
I0901 08:17:40.475734  5524 task_status_update_manager.cpp:188] Resuming sending task status updates
I0901 08:17:40.476184  5519 slave.cpp:1733] Checkpointing SlaveInfo to '/tmp/MasterAllocatorTest_0_SlaveLost_cpbrRU/meta/slaves/a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-S1/slave.info'
I0901 08:17:40.476327  5525 status_update_manager_process.hpp:385] Resuming operation status update manager
I0901 08:17:40.477620  5529 hierarchical.cpp:1935] Performed allocation for 1 agents in 1.771644ms
I0901 08:17:40.478152  5519 slave.cpp:1793] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"/76qu2FnQzewKeQ9aoPh9Q=="},"slave_id":{"value":"a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-S1"},"update_oversubscribed_resources":false}
I0901 08:17:40.478534  5517 master.cpp:9536] Sending offers [ a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-O1 ] to framework a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-0000 (default) at scheduler-c1f5712c-4f60-4d7b-8181-040a2d5a3f86@172.17.0.3:34493
I0901 08:17:40.479519  5522 sched.cpp:934] Scheduler::resourceOffers took 144779ns
I0901 08:17:40.479924  5517 master.cpp:7635] Ignoring update on agent a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-S1 at slave(117)@172.17.0.3:34493 (0f73b3326edc) as it reports no changes
I0901 08:17:40.481137  5510 sched.cpp:2166] Asked to stop the driver
I0901 08:17:40.481338  5528 sched.cpp:1204] Stopping framework a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-0000
I0901 08:17:40.481608  5512 master.cpp:10323] Processing TEARDOWN call for framework a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-0000 (default) at scheduler-c1f5712c-4f60-4d7b-8181-040a2d5a3f86@172.17.0.3:34493
I0901 08:17:40.481647  5512 master.cpp:10335] Removing framework a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-0000 (default) at scheduler-c1f5712c-4f60-4d7b-8181-040a2d5a3f86@172.17.0.3:34493
I0901 08:17:40.481667  5512 master.cpp:3385] Deactivating framework a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-0000 (default) at scheduler-c1f5712c-4f60-4d7b-8181-040a2d5a3f86@172.17.0.3:34493
I0901 08:17:40.482082  5531 hierarchical.cpp:887] Deactivated framework a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-0000
I0901 08:17:40.482350  5512 master.cpp:11834] Removing offer a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-O1
I0901 08:17:40.482507  5510 slave.cpp:1002] Agent terminating
I0901 08:17:40.482956  5531 hierarchical.cpp:1658] Recovered ports(allocated: *):[31000-32000]; cpus(allocated: *):3; mem(allocated: *):256; disk(allocated: *):1024 (total: cpus:3; mem:256; disk:1024; ports:[31000-32000], offered or allocated: {}) on agent a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-S1 from framework a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-0000
I0901 08:17:40.484767  5531 hierarchical.cpp:1859] Allocation paused
I0901 08:17:40.485359  5531 hierarchical.cpp:831] Removed framework a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-0000
I0901 08:17:40.485450  5531 hierarchical.cpp:1869] Allocation resumed
I0901 08:17:40.627272  5521 master.cpp:1297] Agent a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-S1 at slave(117)@172.17.0.3:34493 (0f73b3326edc) disconnected
I0901 08:17:40.627331  5521 master.cpp:3420] Disconnecting agent a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-S1 at slave(117)@172.17.0.3:34493 (0f73b3326edc)
I0901 08:17:40.627434  5521 master.cpp:3439] Deactivating agent a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-S1 at slave(117)@172.17.0.3:34493 (0f73b3326edc)
I0901 08:17:40.627660  5518 hierarchical.cpp:1238] Agent a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-S1 deactivated
I0901 08:17:40.644981  5510 master.cpp:1145] Master terminating
I0901 08:17:40.645311  5515 hierarchical.cpp:1214] Removed all filters for agent a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-S1
I0901 08:17:40.645337  5515 hierarchical.cpp:1090] Removed agent a7738cb3-b080-4ca4-bcd8-e8046bbcf5bb-S1
[       OK ] MasterAllocatorTest/0.SlaveLost (424 ms)
[ RUN      ] MasterAllocatorTest/0.SlaveAdded
I0901 08:17:40.657145  5510 cluster.cpp:195] Creating default 'local' authorizer
I0901 08:17:40.661676  5533 master.cpp:448] Master 411a707d-17a7-4838-9b3a-3770d00bb1e0 (0f73b3326edc) started on 172.17.0.3:34493
I0901 08:17:40.661712  5533 master.cpp:451] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --allocator="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/AgK9ah/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_operator_event_stream_subscribers="1000" --max_unreachable_tasks_per_framework="1000" --memory_profiling="false" --min_allocatable_resources="cpus:0.01|mem:32" --offer_constraints_re2_max_mem="4KB" --offer_constraints_re2_max_program_size="100" --port="5050" --publish_per_framework_metrics="true" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --require_agent_domain="false" --role_sorter="drf" --root_submissions="true" --version="false" --webui_dir="/tmp/SRC/build/mesos-1.11.0/_inst/share/mesos/webui" --work_dir="/tmp/AgK9ah/master" --zk_session_timeout="10secs"
I0901 08:17:40.662123  5533 master.cpp:500] Master only allowing authenticated frameworks to register
I0901 08:17:40.662147  5533 master.cpp:506] Master only allowing authenticated agents to register
I0901 08:17:40.662164  5533 master.cpp:512] Master only allowing authenticated HTTP frameworks to register
I0901 08:17:40.662184  5533 credentials.hpp:37] Loading credentials for authentication from '/tmp/AgK9ah/credentials'
I0901 08:17:40.662443  5533 master.cpp:556] Using default 'crammd5' authenticator
I0901 08:17:40.662645  5533 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0901 08:17:40.662837  5533 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0901 08:17:40.663022  5533 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0901 08:17:40.663199  5533 master.cpp:637] Authorization enabled
I0901 08:17:40.663590  5521 whitelist_watcher.cpp:77] No whitelist given
I0901 08:17:40.663617  5513 hierarchical.cpp:637] Initialized hierarchical allocator process
I0901 08:17:40.667326  5534 master.cpp:2170] Elected as the leading master!
I0901 08:17:40.667383  5534 master.cpp:1666] Recovering from registrar
I0901 08:17:40.667618  5512 registrar.cpp:339] Recovering registrar
I0901 08:17:40.668231  5512 registrar.cpp:383] Successfully fetched the registry (0B) in 553984ns
I0901 08:17:40.668356  5512 registrar.cpp:487] Applied 1 operations in 31836ns; attempting to update the registry
I0901 08:17:40.669070  5528 registrar.cpp:544] Successfully updated the registry in 658176ns
I0901 08:17:40.669217  5528 registrar.cpp:416] Successfully recovered registrar
I0901 08:17:40.670018  5523 master.cpp:1819] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister
I0901 08:17:40.670032  5520 hierarchical.cpp:676] Skipping recovery of hierarchical allocator: nothing to recover
W0901 08:17:40.678612  5510 process.cpp:2877] Attempted to spawn already running process files@172.17.0.3:34493
I0901 08:17:40.679234  5510 resolver.cpp:69] Creating default secret resolver
I0901 08:17:40.679352  5510 cluster.cpp:620] Creating default 'local' authorizer
I0901 08:17:40.681483  5526 slave.cpp:281] Mesos agent started on (118)@172.17.0.3:34493
I0901 08:17:40.681512  5526 slave.cpp:282] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/AgK9ah/shW3tj/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authentication_timeout_max="1mins" --authentication_timeout_min="5secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_destroy_timeout="1mins" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/AgK9ah/shW3tj/credential" --default_role="*" --disallow_sharing_agent_ipc_namespace="false" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_ignore_runtime="false" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/AgK9ah/shW3tj/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --docker_volume_chown="false" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/AgK9ah/shW3tj/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/AgK9ah/shW3tj/frameworks" --gc_delay="1weeks" --gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/AgK9ah/shW3tj/http_credentials" --http_executor_domain_sockets="false" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/tmp/SRC/build/mesos-1.11.0/_build/sub/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:3;mem:1024" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/MasterAllocatorTest_0_SlaveAdded_SlgKnD" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/MasterAllocatorTest_0_SlaveAdded_RelrhX" --zk_session_timeout="10secs"
I0901 08:17:40.682020  5526 credentials.hpp:73] Loading credential for authentication from '/tmp/AgK9ah/shW3tj/credential'
W0901 08:17:40.682154  5510 process.cpp:2877] Attempted to spawn already running process version@172.17.0.3:34493
I0901 08:17:40.682162  5526 slave.cpp:314] Agent using credential for: test-principal
I0901 08:17:40.682204  5526 credentials.hpp:37] Loading credentials for authentication from '/tmp/AgK9ah/shW3tj/http_credentials'
I0901 08:17:40.682533  5526 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0901 08:17:40.682973  5526 disk_profile_adaptor.cpp:78] Creating default disk profile adaptor module
I0901 08:17:40.683362  5510 sched.cpp:239] Version: 1.11.0
I0901 08:17:40.684167  5527 sched.cpp:343] New master detected at master@172.17.0.3:34493
I0901 08:17:40.684306  5527 sched.cpp:408] Authenticating with master master@172.17.0.3:34493
I0901 08:17:40.684330  5527 sched.cpp:415] Using default CRAM-MD5 authenticatee
I0901 08:17:40.684108  5526 slave.cpp:629] Agent resources: [{"name":"cpus","scalar":{"value":3.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":3748421.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I0901 08:17:40.684509  5526 slave.cpp:637] Agent attributes: [  ]
I0901 08:17:40.684535  5526 slave.cpp:646] Agent hostname: 0f73b3326edc
I0901 08:17:40.684727  5514 authenticatee.cpp:121] Creating new client SASL connection
I0901 08:17:40.684841  5533 task_status_update_manager.cpp:181] Pausing sending task status updates
I0901 08:17:40.684875  5525 status_update_manager_process.hpp:379] Pausing operation status update manager
I0901 08:17:40.685048  5527 master.cpp:9727] Authenticating scheduler-bfdd3ba8-a8c3-43bb-b2c7-df480d6ea530@172.17.0.3:34493
I0901 08:17:40.685175  5530 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(265)@172.17.0.3:34493
I0901 08:17:40.685602  5522 authenticator.cpp:98] Creating new server SASL connection
I0901 08:17:40.685921  5512 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0901 08:17:40.685958  5512 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0901 08:17:40.686089  5512 authenticator.cpp:204] Received SASL authentication start
I0901 08:17:40.686156  5512 authenticator.cpp:326] Authentication requires more steps
I0901 08:17:40.686259  5512 authenticatee.cpp:259] Received SASL authentication step
I0901 08:17:40.686437  5511 authenticator.cpp:232] Received SASL authentication step
I0901 08:17:40.686488  5511 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '0f73b3326edc' server FQDN: '0f73b3326edc' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0901 08:17:40.686511  5511 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0901 08:17:40.686561  5511 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0901 08:17:40.686596  5511 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '0f73b3326edc' server FQDN: '0f73b3326edc' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0901 08:17:40.686614  5511 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0901 08:17:40.686625  5511 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0901 08:17:40.686642  5511 authenticator.cpp:318] Authentication success
I0901 08:17:40.686805  5528 authenticatee.cpp:299] Authentication success
I0901 08:17:40.686885  5511 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(265)@172.17.0.3:34493
I0901 08:17:40.686918  5529 master.cpp:9759] Successfully authenticated principal 'test-principal' at scheduler-bfdd3ba8-a8c3-43bb-b2c7-df480d6ea530@172.17.0.3:34493
I0901 08:17:40.687321  5521 sched.cpp:520] Successfully authenticated with master master@172.17.0.3:34493
I0901 08:17:40.687366  5521 sched.cpp:835] Sending SUBSCRIBE call to master@172.17.0.3:34493
I0901 08:17:40.687374  5519 state.cpp:68] Recovering state from '/tmp/MasterAllocatorTest_0_SlaveAdded_RelrhX/meta'
I0901 08:17:40.687568  5521 sched.cpp:870] Will retry registration in 1.649102339secs if necessary
I0901 08:17:40.687750  5533 slave.cpp:7741] Finished recovering checkpointed state from '/tmp/MasterAllocatorTest_0_SlaveAdded_RelrhX/meta', beginning agent recovery
I0901 08:17:40.687906  5534 master.cpp:2941] Received SUBSCRIBE call for framework 'default' at scheduler-bfdd3ba8-a8c3-43bb-b2c7-df480d6ea530@172.17.0.3:34493
I0901 08:17:40.688499  5525 task_status_update_manager.cpp:207] Recovering task status update manager
I0901 08:17:40.690212  5523 composing.cpp:343] Finished recovering all containerizers
I0901 08:17:40.690639  5528 slave.cpp:8223] Recovering executors
I0901 08:17:40.690745  5528 slave.cpp:8376] Finished recovery
I0901 08:17:40.691303  5511 master.cpp:3024] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0901 08:17:40.691617  5518 task_status_update_manager.cpp:181] Pausing sending task status updates
I0901 08:17:40.691676  5519 status_update_manager_process.hpp:379] Pausing operation status update manager
I0901 08:17:40.691717  5517 slave.cpp:1473] New master detected at master@172.17.0.3:34493
I0901 08:17:40.691884  5517 slave.cpp:1538] Detecting new master
I0901 08:17:40.693183  5525 slave.cpp:1565] Authenticating with master master@172.17.0.3:34493
I0901 08:17:40.693266  5525 slave.cpp:1574] Using default CRAM-MD5 authenticatee
I0901 08:17:40.693564  5530 authenticatee.cpp:121] Creating new client SASL connection
I0901 08:17:40.693930  5511 master.cpp:9958] Adding framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000 (default) at scheduler-bfdd3ba8-a8c3-43bb-b2c7-df480d6ea530@172.17.0.3:34493 with roles {  } suppressed
I0901 08:17:40.694847  5511 master.cpp:9727] Authenticating slave(118)@172.17.0.3:34493
I0901 08:17:40.694898  5522 sched.cpp:751] Framework registered with 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000
I0901 08:17:40.695005  5522 sched.cpp:770] Scheduler::registered took 55622ns
I0901 08:17:40.695037  5512 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(266)@172.17.0.3:34493
I0901 08:17:40.695310  5534 hierarchical.cpp:774] Added framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000
I0901 08:17:40.695389  5524 authenticator.cpp:98] Creating new server SASL connection
I0901 08:17:40.695612  5534 hierarchical.cpp:1935] Performed allocation for 0 agents in 107932ns
I0901 08:17:40.695772  5532 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0901 08:17:40.695825  5532 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0901 08:17:40.696012  5515 authenticator.cpp:204] Received SASL authentication start
I0901 08:17:40.696123  5515 authenticator.cpp:326] Authentication requires more steps
I0901 08:17:40.696275  5515 authenticatee.cpp:259] Received SASL authentication step
I0901 08:17:40.696444  5513 authenticator.cpp:232] Received SASL authentication step
I0901 08:17:40.696492  5513 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '0f73b3326edc' server FQDN: '0f73b3326edc' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0901 08:17:40.696509  5513 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0901 08:17:40.696542  5513 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0901 08:17:40.696574  5513 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '0f73b3326edc' server FQDN: '0f73b3326edc' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0901 08:17:40.696593  5513 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0901 08:17:40.696609  5513 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0901 08:17:40.696630  5513 authenticator.cpp:318] Authentication success
I0901 08:17:40.696815  5523 authenticatee.cpp:299] Authentication success
I0901 08:17:40.696846  5520 master.cpp:9759] Successfully authenticated principal 'test-principal' at slave(118)@172.17.0.3:34493
I0901 08:17:40.696907  5528 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(266)@172.17.0.3:34493
I0901 08:17:40.697320  5533 slave.cpp:1665] Successfully authenticated with master master@172.17.0.3:34493
I0901 08:17:40.697829  5533 slave.cpp:2131] Will retry registration in 9.743236ms if necessary
I0901 08:17:40.697994  5519 master.cpp:6221] Received register agent message from slave(118)@172.17.0.3:34493 (0f73b3326edc)
I0901 08:17:40.698468  5519 master.cpp:3752] Authorizing principal 'test-principal' to perform action REGISTER_AGENT on ANY object
I0901 08:17:40.699097  5525 master.cpp:6288] Authorized registration of agent at slave(118)@172.17.0.3:34493 (0f73b3326edc)
I0901 08:17:40.699183  5525 master.cpp:6400] Registering agent at slave(118)@172.17.0.3:34493 (0f73b3326edc) with id 411a707d-17a7-4838-9b3a-3770d00bb1e0-S0
I0901 08:17:40.699924  5522 registrar.cpp:487] Applied 1 operations in 315161ns; attempting to update the registry
I0901 08:17:40.700634  5522 registrar.cpp:544] Successfully updated the registry in 641024ns
I0901 08:17:40.700858  5532 master.cpp:6448] Admitted agent 411a707d-17a7-4838-9b3a-3770d00bb1e0-S0 at slave(118)@172.17.0.3:34493 (0f73b3326edc)
I0901 08:17:40.701766  5515 slave.cpp:1698] Registered with master master@172.17.0.3:34493; given agent ID 411a707d-17a7-4838-9b3a-3770d00bb1e0-S0
I0901 08:17:40.701755  5532 master.cpp:6493] Registered agent 411a707d-17a7-4838-9b3a-3770d00bb1e0-S0 at slave(118)@172.17.0.3:34493 (0f73b3326edc) with cpus:3; mem:1024; disk:3748421; ports:[31000-32000]
I0901 08:17:40.701877  5513 hierarchical.cpp:1041] Added agent 411a707d-17a7-4838-9b3a-3770d00bb1e0-S0 (0f73b3326edc) with cpus:3; mem:1024; disk:3748421; ports:[31000-32000] (offered or allocated: {})
I0901 08:17:40.701942  5526 task_status_update_manager.cpp:188] Resuming sending task status updates
I0901 08:17:40.702283  5515 slave.cpp:1733] Checkpointing SlaveInfo to '/tmp/MasterAllocatorTest_0_SlaveAdded_RelrhX/meta/slaves/411a707d-17a7-4838-9b3a-3770d00bb1e0-S0/slave.info'
I0901 08:17:40.702376  5516 status_update_manager_process.hpp:385] Resuming operation status update manager
I0901 08:17:40.703186  5513 hierarchical.cpp:1935] Performed allocation for 1 agents in 1.100406ms
I0901 08:17:40.703665  5515 slave.cpp:1793] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"8agVmbDiRg2eNG+jcLC2Ug=="},"slave_id":{"value":"411a707d-17a7-4838-9b3a-3770d00bb1e0-S0"},"update_oversubscribed_resources":false}
I0901 08:17:40.703969  5521 master.cpp:9536] Sending offers [ 411a707d-17a7-4838-9b3a-3770d00bb1e0-O0 ] to framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000 (default) at scheduler-bfdd3ba8-a8c3-43bb-b2c7-df480d6ea530@172.17.0.3:34493
I0901 08:17:40.704869  5521 master.cpp:7635] Ignoring update on agent 411a707d-17a7-4838-9b3a-3770d00bb1e0-S0 at slave(118)@172.17.0.3:34493 (0f73b3326edc) as it reports no changes
I0901 08:17:40.705334  5517 sched.cpp:934] Scheduler::resourceOffers took 808506ns
I0901 08:17:40.706822  5527 master.cpp:4314] Processing ACCEPT call for offers: [ 411a707d-17a7-4838-9b3a-3770d00bb1e0-O0 ] on agent 411a707d-17a7-4838-9b3a-3770d00bb1e0-S0 at slave(118)@172.17.0.3:34493 (0f73b3326edc) for framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000 (default) at scheduler-bfdd3ba8-a8c3-43bb-b2c7-df480d6ea530@172.17.0.3:34493
I0901 08:17:40.707334  5527 master.cpp:11834] Removing offer 411a707d-17a7-4838-9b3a-3770d00bb1e0-O0
W0901 08:17:40.708770  5527 validation.cpp:1716] Executor 'default' for task '8393ffae-0a73-454e-8d50-f2d4ebbbe29f' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
W0901 08:17:40.708806  5527 validation.cpp:1728] Executor 'default' for task '8393ffae-0a73-454e-8d50-f2d4ebbbe29f' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
I0901 08:17:40.709085  5Build timed out (after 240 minutes). Marking the build as failed.
527 master.cpp:3831] Adding executor 'default' with resources {} of framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000 (default) at scheduler-bfdd3ba8-a8c3-43bb-b2c7-df480d6ea530@172.17.0.3:34493 on agent 411a707d-17a7-4838-9b3a-3770d00bb1e0-S0 at slave(118)@172.17.0.3:34493 (0f73b3326edc)
I0901 08:17:40.709285  5527 master.cpp:3857] Adding task 8393ffae-0a73-454e-8d50-f2d4ebbbe29f with resources cpus(allocated: *):2; mem(allocated: *):512 of framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000 (default) at scheduler-bfdd3ba8-a8c3-43bb-b2c7-df480d6ea530@172.17.0.3:34493 on agent 411a707d-17a7-4838-9b3a-3770d00bb1e0-S0 at slave(118)@172.17.0.3:34493 (0f73b3326edc)
I0901 08:17:40.709758  5527 master.cpp:4993] Launching task 8393ffae-0a73-454e-8d50-f2d4ebbbe29f of framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000 (default) at scheduler-bfdd3ba8-a8c3-43bb-b2c7-df480d6ea530@172.17.0.3:34493 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] on agent 411a707d-17a7-4838-9b3a-3770d00bb1e0-S0 at slave(118)@172.17.0.3:34493 (0f73b3326edc) on  new executor
I0901 08:17:40.710254  5530 hierarchical.cpp:1859] Allocation paused
I0901 08:17:40.710641  5530 hierarchical.cpp:1658] Recovered ports(allocated: *):[31000-32000]; cpus(allocated: *):1; mem(allocated: *):512; disk(allocated: *):3748421 (total: cpus:3; mem:1024; disk:3748421; ports:[31000-32000], offered or allocated: mem(allocated: *):512; cpus(allocated: *):2) on agent 411a707d-17a7-4838-9b3a-3770d00bb1e0-S0 from framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000
I0901 08:17:40.710997  5519 slave.cpp:2300] Got assigned task '8393ffae-0a73-454e-8d50-f2d4ebbbe29f' for framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000
I0901 08:17:40.711627  5530 hierarchical.cpp:1707] Framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000 filtered agent 411a707d-17a7-4838-9b3a-3770d00bb1e0-S0 for 100ms
I0901 08:17:40.712308  5530 hierarchical.cpp:1869] Allocation resumed
I0901 08:17:40.712750  5519 slave.cpp:2707] Authorizing task '8393ffae-0a73-454e-8d50-f2d4ebbbe29f' for framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000
I0901 08:17:40.712846  5519 slave.cpp:9715] Authorizing framework principal 'test-principal' to launch task 8393ffae-0a73-454e-8d50-f2d4ebbbe29f
I0901 08:17:40.715116  5514 slave.cpp:3181] Launching task '8393ffae-0a73-454e-8d50-f2d4ebbbe29f' for framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000
I0901 08:17:40.715117  5532 hierarchical.cpp:2764] Filtered offer with ports:[31000-32000]; cpus:1; mem:512; disk:3748421 on agent 411a707d-17a7-4838-9b3a-3770d00bb1e0-S0 for role * of framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000
I0901 08:17:40.715216  5514 paths.cpp:832] Creating sandbox '/tmp/MasterAllocatorTest_0_SlaveAdded_RelrhX/slaves/411a707d-17a7-4838-9b3a-3770d00bb1e0-S0/frameworks/411a707d-17a7-4838-9b3a-3770d00bb1e0-0000/executors/default/runs/2cc9e88a-57e5-4a78-b235-58d3bca4ff52' for user 'mesos'
I0901 08:17:40.715234  5532 hierarchical.cpp:1935] Performed allocation for 1 agents in 418164ns
I0901 08:17:40.716020  5514 slave.cpp:10379] Launching executor 'default' of framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000 with resources [] in work directory '/tmp/MasterAllocatorTest_0_SlaveAdded_RelrhX/slaves/411a707d-17a7-4838-9b3a-3770d00bb1e0-S0/frameworks/411a707d-17a7-4838-9b3a-3770d00bb1e0-0000/executors/default/runs/2cc9e88a-57e5-4a78-b235-58d3bca4ff52'
I0901 08:17:40.717340  5514 slave.cpp:3415] Queued task '8393ffae-0a73-454e-8d50-f2d4ebbbe29f' for executor 'default' of framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000
I0901 08:17:40.717478  5514 slave.cpp:1206] Successfully attached '/tmp/MasterAllocatorTest_0_SlaveAdded_RelrhX/slaves/411a707d-17a7-4838-9b3a-3770d00bb1e0-S0/frameworks/411a707d-17a7-4838-9b3a-3770d00bb1e0-0000/executors/default/runs/2cc9e88a-57e5-4a78-b235-58d3bca4ff52' to virtual path '/tmp/MasterAllocatorTest_0_SlaveAdded_RelrhX/slaves/411a707d-17a7-4838-9b3a-3770d00bb1e0-S0/frameworks/411a707d-17a7-4838-9b3a-3770d00bb1e0-0000/executors/default/runs/latest'
I0901 08:17:40.717541  5514 slave.cpp:1206] Successfully attached '/tmp/MasterAllocatorTest_0_SlaveAdded_RelrhX/slaves/411a707d-17a7-4838-9b3a-3770d00bb1e0-S0/frameworks/411a707d-17a7-4838-9b3a-3770d00bb1e0-0000/executors/default/runs/2cc9e88a-57e5-4a78-b235-58d3bca4ff52' to virtual path '/frameworks/411a707d-17a7-4838-9b3a-3770d00bb1e0-0000/executors/default/runs/latest'
I0901 08:17:40.717595  5514 slave.cpp:1206] Successfully attached '/tmp/MasterAllocatorTest_0_SlaveAdded_RelrhX/slaves/411a707d-17a7-4838-9b3a-3770d00bb1e0-S0/frameworks/411a707d-17a7-4838-9b3a-3770d00bb1e0-0000/executors/default/runs/2cc9e88a-57e5-4a78-b235-58d3bca4ff52' to virtual path '/tmp/MasterAllocatorTest_0_SlaveAdded_RelrhX/slaves/411a707d-17a7-4838-9b3a-3770d00bb1e0-S0/frameworks/411a707d-17a7-4838-9b3a-3770d00bb1e0-0000/executors/default/runs/2cc9e88a-57e5-4a78-b235-58d3bca4ff52'
I0901 08:17:40.718217  5514 slave.cpp:3876] Launching container 2cc9e88a-57e5-4a78-b235-58d3bca4ff52 for executor 'default' of framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000
W0901 08:17:40.719348  5513 process.cpp:2877] Attempted to spawn already running process version@172.17.0.3:34493
I0901 08:17:40.719616  5513 exec.cpp:164] Version: 1.11.0
I0901 08:17:40.719998  5518 exec.cpp:213] Executor started at: executor(32)@172.17.0.3:34493 with pid 5510
I0901 08:17:40.720309  5518 slave.cpp:5487] Got registration for executor 'default' of framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000 from executor(32)@172.17.0.3:34493
I0901 08:17:40.720947  5515 exec.cpp:237] Executor registered on agent 411a707d-17a7-4838-9b3a-3770d00bb1e0-S0
I0901 08:17:40.721024  5515 exec.cpp:249] Executor::registered took 31440ns
I0901 08:17:40.722517  5525 slave.cpp:3641] Sending queued task '8393ffae-0a73-454e-8d50-f2d4ebbbe29f' to executor 'default' of framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000 at executor(32)@172.17.0.3:34493
I0901 08:17:40.722972  5512 exec.cpp:331] Executor asked to run task '8393ffae-0a73-454e-8d50-f2d4ebbbe29f'
I0901 08:17:40.723104  5512 exec.cpp:340] Executor::launchTask took 103098ns
I0901 08:17:40.723224  5512 exec.cpp:614] Executor sending status update TASK_RUNNING (Status UUID: b6f9c3d3-66a4-44a4-8287-2613960a8146) for task 8393ffae-0a73-454e-8d50-f2d4ebbbe29f of framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000
I0901 08:17:40.723606  5512 slave.cpp:5980] Handling status update TASK_RUNNING (Status UUID: b6f9c3d3-66a4-44a4-8287-2613960a8146) for task 8393ffae-0a73-454e-8d50-f2d4ebbbe29f of framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000 from executor(32)@172.17.0.3:34493
I0901 08:17:40.724494  5512 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: b6f9c3d3-66a4-44a4-8287-2613960a8146) for task 8393ffae-0a73-454e-8d50-f2d4ebbbe29f of framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000
I0901 08:17:40.724545  5512 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 8393ffae-0a73-454e-8d50-f2d4ebbbe29f of framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000
I0901 08:17:40.725277  5512 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: b6f9c3d3-66a4-44a4-8287-2613960a8146) for task 8393ffae-0a73-454e-8d50-f2d4ebbbe29f of framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000 to the agent
I0901 08:17:40.725636  5516 slave.cpp:6526] Forwarding the update TASK_RUNNING (Status UUID: b6f9c3d3-66a4-44a4-8287-2613960a8146) for task 8393ffae-0a73-454e-8d50-f2d4ebbbe29f of framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000 to master@172.17.0.3:34493
I0901 08:17:40.725950  5516 slave.cpp:6410] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: b6f9c3d3-66a4-44a4-8287-2613960a8146) for task 8393ffae-0a73-454e-8d50-f2d4ebbbe29f of framework 411a707d-17a7-4838-9b3a-3770d00bb1e0-0000
I0901 08:17:40.726104  5528 master.cpp:8117] Status update TASK_RUNNING (Status UUID: b6f9c3d3-66a4-44a4-8287-2613960a8146) for task 8393ffae-0a73-454e-8d50-f2d4ebbbe29f of framework 411a7Build was aborted
07d-17a7-4838-9b3a-3770d00bb1e0-0000 from agent 411a707d-17a7-4838-9b3a-3770d00bb1e0-S0 at slave(118)@172.17.0.3:34493 (0f73b3326edc)