mesos-builds mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject Build failed in Jenkins: Mesos-Reviewbot #21544
Date Tue, 06 Feb 2018 09:34:20 GMT
See <https://builds.apache.org/job/Mesos-Reviewbot/21544/display/redirect>

------------------------------------------
[...truncated 31.35 MB...]
I0206 09:34:16.658306  6597 state.cpp:66] Recovering state from '/tmp/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_SZkg09/meta'
I0206 09:34:16.658893  6597 task_status_update_manager.cpp:207] Recovering task status update
manager
I0206 09:34:16.659255  6595 containerizer.cpp:674] Recovering containerizer
I0206 09:34:16.662253  6603 provisioner.cpp:495] Provisioner recovery complete
I0206 09:34:16.662808  6602 slave.cpp:6824] Finished recovery
I0206 09:34:16.663869  6609 task_status_update_manager.cpp:181] Pausing sending task status
updates
I0206 09:34:16.663890  6589 slave.cpp:1146] New master detected at master@172.17.0.4:38512
I0206 09:34:16.664093  6589 slave.cpp:1201] Detecting new master
I0206 09:34:16.672633  6593 slave.cpp:1228] Authenticating with master master@172.17.0.4:38512
I0206 09:34:16.672782  6593 slave.cpp:1237] Using default CRAM-MD5 authenticatee
I0206 09:34:16.673260  6601 authenticatee.cpp:121] Creating new client SASL connection
I0206 09:34:16.673853  6597 master.cpp:8978] Authenticating slave(857)@172.17.0.4:38512
I0206 09:34:16.674130  6598 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1508)@172.17.0.4:38512
I0206 09:34:16.674595  6587 authenticator.cpp:98] Creating new server SASL connection
I0206 09:34:16.674993  6600 authenticatee.cpp:213] Received SASL authentication mechanisms:
CRAM-MD5
I0206 09:34:16.675043  6600 authenticatee.cpp:239] Attempting to authenticate with mechanism
'CRAM-MD5'
I0206 09:34:16.675237  6605 authenticator.cpp:204] Received SASL authentication start
I0206 09:34:16.675335  6605 authenticator.cpp:326] Authentication requires more steps
I0206 09:34:16.675545  6591 authenticatee.cpp:259] Received SASL authentication step
I0206 09:34:16.675772  6610 authenticator.cpp:232] Received SASL authentication step
I0206 09:34:16.675829  6610 auxprop.cpp:109] Request to lookup properties for user: 'test-principal'
realm: '4cb9abc5a66d' server FQDN: '4cb9abc5a66d' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0206 09:34:16.675856  6610 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0206 09:34:16.675923  6610 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0206 09:34:16.675962  6610 auxprop.cpp:109] Request to lookup properties for user: 'test-principal'
realm: '4cb9abc5a66d' server FQDN: '4cb9abc5a66d' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0206 09:34:16.675984  6610 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since
SASL_AUXPROP_AUTHZID == true
I0206 09:34:16.676002  6610 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5'
since SASL_AUXPROP_AUTHZID == true
I0206 09:34:16.676031  6610 authenticator.cpp:318] Authentication success
I0206 09:34:16.676183  6596 authenticatee.cpp:299] Authentication success
I0206 09:34:16.676331  6595 master.cpp:9008] Successfully authenticated principal 'test-principal'
at slave(857)@172.17.0.4:38512
I0206 09:34:16.676381  6592 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1508)@172.17.0.4:38512
I0206 09:34:16.676671  6608 slave.cpp:1320] Successfully authenticated with master master@172.17.0.4:38512
I0206 09:34:16.677167  6608 slave.cpp:1766] Will retry registration in 19.052286ms if necessary
I0206 09:34:16.677413  6603 master.cpp:6013] Received register agent message from slave(857)@172.17.0.4:38512
(4cb9abc5a66d)
I0206 09:34:16.677795  6603 master.cpp:3793] Authorizing agent providing resources 'cpus:2;
mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_QdvzA8/disk1]:2048;
disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_QdvzA8/disk2]:2048;
ports:[31000-32000]' with principal 'test-principal'
I0206 09:34:16.678316  6603 master.cpp:3573] Authorizing principal 'test-principal' to reserve
resources 'cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_QdvzA8/disk1]:2048;
disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_QdvzA8/disk2]:2048;
ports:[31000-32000]'
I0206 09:34:16.679319  6593 master.cpp:6084] Authorized registration of agent at slave(857)@172.17.0.4:38512
(4cb9abc5a66d)
I0206 09:34:16.679471  6593 master.cpp:6195] Registering agent at slave(857)@172.17.0.4:38512
(4cb9abc5a66d) with id 7b59cc87-bed8-427c-8d30-e44309484ca3-S0
I0206 09:34:16.680555  6597 registrar.cpp:495] Applied 1 operations in 363582ns; attempting
to update the registry
I0206 09:34:16.681787  6597 registrar.cpp:552] Successfully updated the registry in 1.111808ms
I0206 09:34:16.682104  6591 master.cpp:6243] Admitted agent 7b59cc87-bed8-427c-8d30-e44309484ca3-S0
at slave(857)@172.17.0.4:38512 (4cb9abc5a66d)
I0206 09:34:16.683656  6610 slave.cpp:1367] Registered with master master@172.17.0.4:38512;
given agent ID 7b59cc87-bed8-427c-8d30-e44309484ca3-S0
I0206 09:34:16.683635  6591 master.cpp:6292] Registered agent 7b59cc87-bed8-427c-8d30-e44309484ca3-S0
at slave(857)@172.17.0.4:38512 (4cb9abc5a66d) with cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_QdvzA8/disk1]:2048;
disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_QdvzA8/disk2]:2048;
ports:[31000-32000]
I0206 09:34:16.683871  6604 task_status_update_manager.cpp:188] Resuming sending task status
updates
I0206 09:34:16.684193  6610 slave.cpp:1387] Checkpointing SlaveInfo to '/tmp/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_SZkg09/meta/slaves/7b59cc87-bed8-427c-8d30-e44309484ca3-S0/slave.info'
I0206 09:34:16.685081  6595 hierarchical.cpp:574] Added agent 7b59cc87-bed8-427c-8d30-e44309484ca3-S0
(4cb9abc5a66d) with cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_QdvzA8/disk1]:2048;
disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_QdvzA8/disk2]:2048;
ports:[31000-32000] (allocated: {})
I0206 09:34:16.685313  6610 slave.cpp:1434] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"W5EUUCMDS3qD8RhIUT3j0w=="},"slave_id":{"value":"7b59cc87-bed8-427c-8d30-e44309484ca3-S0"},"update_oversubscribed_resources":true}
I0206 09:34:16.685920  6595 hierarchical.cpp:1517] Performed allocation for 1 agents in 350193ns
I0206 09:34:16.686197  6608 master.cpp:7235] Received update of agent 7b59cc87-bed8-427c-8d30-e44309484ca3-S0
at slave(857)@172.17.0.4:38512 (4cb9abc5a66d) with total oversubscribed resources {}
I0206 09:34:16.686673  6608 master.cpp:7329] Ignoring update on agent 7b59cc87-bed8-427c-8d30-e44309484ca3-S0
at slave(857)@172.17.0.4:38512 (4cb9abc5a66d) as it reports no changes
W0206 09:34:16.687319  6586 process.cpp:2805] Attempted to spawn already running process version@172.17.0.4:38512
I0206 09:34:16.689622  6586 sched.cpp:232] Version: 1.6.0
I0206 09:34:16.690574  6598 sched.cpp:336] New master detected at master@172.17.0.4:38512
I0206 09:34:16.690760  6598 sched.cpp:396] Authenticating with master master@172.17.0.4:38512
I0206 09:34:16.690798  6598 sched.cpp:403] Using default CRAM-MD5 authenticatee
I0206 09:34:16.691166  6600 authenticatee.cpp:121] Creating new client SASL connection
I0206 09:34:16.691633  6597 master.cpp:8978] Authenticating scheduler-1be756eb-5efc-45cb-95ff-63640e49a688@172.17.0.4:38512
I0206 09:34:16.691874  6596 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1509)@172.17.0.4:38512
I0206 09:34:16.692335  6594 authenticator.cpp:98] Creating new server SASL connection
I0206 09:34:16.692687  6591 authenticatee.cpp:213] Received SASL authentication mechanisms:
CRAM-MD5
I0206 09:34:16.692735  6591 authenticatee.cpp:239] Attempting to authenticate with mechanism
'CRAM-MD5'
I0206 09:34:16.692975  6604 authenticator.cpp:204] Received SASL authentication start
I0206 09:34:16.693066  6604 authenticator.cpp:326] Authentication requires more steps
I0206 09:34:16.693254  6588 authenticatee.cpp:259] Received SASL authentication step
I0206 09:34:16.693411  6588 authenticator.cpp:232] Received SASL authentication step
I0206 09:34:16.693452  6588 auxprop.cpp:109] Request to lookup properties for user: 'test-principal'
realm: '4cb9abc5a66d' server FQDN: '4cb9abc5a66d' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0206 09:34:16.693470  6588 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0206 09:34:16.693511  6588 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0206 09:34:16.693538  6588 auxprop.cpp:109] Request to lookup properties for user: 'test-principal'
realm: '4cb9abc5a66d' server FQDN: '4cb9abc5a66d' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0206 09:34:16.693554  6588 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since
SASL_AUXPROP_AUTHZID == true
I0206 09:34:16.693564  6588 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5'
since SASL_AUXPROP_AUTHZID == true
I0206 09:34:16.693586  6588 authenticator.cpp:318] Authentication success
I0206 09:34:16.693712  6592 authenticatee.cpp:299] Authentication success
I0206 09:34:16.693815  6606 master.cpp:9008] Successfully authenticated principal 'test-principal'
at scheduler-1be756eb-5efc-45cb-95ff-63640e49a688@172.17.0.4:38512
I0206 09:34:16.693851  6590 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1509)@172.17.0.4:38512
I0206 09:34:16.694195  6595 sched.cpp:502] Successfully authenticated with master master@172.17.0.4:38512
I0206 09:34:16.694223  6595 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.4:38512
I0206 09:34:16.694357  6595 sched.cpp:857] Will retry registration in 748.134598ms if necessary
I0206 09:34:16.694558  6599 master.cpp:2869] Received SUBSCRIBE call for framework 'default'
at scheduler-1be756eb-5efc-45cb-95ff-63640e49a688@172.17.0.4:38512
I0206 09:34:16.694651  6599 master.cpp:2198] Authorizing framework principal 'test-principal'
to receive offers for roles '{ default-role }'
I0206 09:34:16.695240  6607 master.cpp:2949] Subscribing framework default with checkpointing
disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0206 09:34:16.695544  6607 master.cpp:9199] Adding framework 7b59cc87-bed8-427c-8d30-e44309484ca3-0000
(default) at scheduler-1be756eb-5efc-45cb-95ff-63640e49a688@172.17.0.4:38512 with roles {
 } suppressed
I0206 09:34:16.696202  6589 sched.cpp:751] Framework registered with 7b59cc87-bed8-427c-8d30-e44309484ca3-0000
I0206 09:34:16.696282  6589 sched.cpp:765] Scheduler::registered took 34969ns
I0206 09:34:16.696475  6601 hierarchical.cpp:297] Added framework 7b59cc87-bed8-427c-8d30-e44309484ca3-0000
I0206 09:34:16.699697  6601 hierarchical.cpp:1517] Performed allocation for 1 agents in 2.925281ms
I0206 09:34:16.701017  6605 master.cpp:8808] Sending 1 offers to framework 7b59cc87-bed8-427c-8d30-e44309484ca3-0000
(default) at scheduler-1be756eb-5efc-45cb-95ff-63640e49a688@172.17.0.4:38512
I0206 09:34:16.701961  6600 sched.cpp:921] Scheduler::resourceOffers took 204325ns
I0206 09:34:16.705101  6592 master.cpp:10716] Removing offer 7b59cc87-bed8-427c-8d30-e44309484ca3-O0
I0206 09:34:16.705592  6592 master.cpp:4220] Processing ACCEPT call for offers: [ 7b59cc87-bed8-427c-8d30-e44309484ca3-O0
] on agent 7b59cc87-bed8-427c-8d30-e44309484ca3-S0 at slave(857)@172.17.0.4:38512 (4cb9abc5a66d)
for framework 7b59cc87-bed8-427c-8d30-e44309484ca3-0000 (default) at scheduler-1be756eb-5efc-45cb-95ff-63640e49a688@172.17.0.4:38512
I0206 09:34:16.705816  6592 master.cpp:3708] Authorizing principal 'test-principal' to create
volumes '[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_QdvzA8\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0206 09:34:16.707880  6590 master.cpp:4696] Applying CREATE operation for volumes [{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_QdvzA8\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]
from framework 7b59cc87-bed8-427c-8d30-e44309484ca3-0000 (default) at scheduler-1be756eb-5efc-45cb-95ff-63640e49a688@172.17.0.4:38512
to agent 7b59cc87-bed8-427c-8d30-e44309484ca3-S0 at slave(857)@172.17.0.4:38512 (4cb9abc5a66d)
I0206 09:34:16.708830  6590 master.cpp:10614] Sending operation '' (uuid: d6cf9aa7-2990-4087-ace6-fa2c9c99ab71)
to agent 7b59cc87-bed8-427c-8d30-e44309484ca3-S0 at slave(857)@172.17.0.4:38512 (4cb9abc5a66d)
I0206 09:34:16.711467  6599 slave.cpp:3760] Updated checkpointed resources from {} to disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_QdvzA8/disk1,id1:path1]:2048
I0206 09:34:16.711606  6599 slave.cpp:7513] Updating the state of operation ' with no ID (uuid:
d6cf9aa7-2990-4087-ace6-fa2c9c99ab71) for framework 7b59cc87-bed8-427c-8d30-e44309484ca3-0000
(latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0206 09:34:16.711933  6599 master.cpp:10374] Updating the state of operation '' (uuid: d6cf9aa7-2990-4087-ace6-fa2c9c99ab71)
for framework 7b59cc87-bed8-427c-8d30-e44309484ca3-0000 (latest state: OPERATION_PENDING,
status update state: OPERATION_FINISHED)
I0206 09:34:16.715013  6609 hierarchical.cpp:925] Updated allocation of framework 7b59cc87-bed8-427c-8d30-e44309484ca3-0000
on agent 7b59cc87-bed8-427c-8d30-e44309484ca3-S0 from cpus(allocated: default-role):2; mem(allocated:
default-role):2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_QdvzA8/disk1]:2048;
disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_QdvzA8/disk2]:2048;
ports(allocated: default-role):[31000-32000] to cpus(allocated: default-role):2; mem(allocated:
default-role):2048; ports(allocated: default-role):[31000-32000]; disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_QdvzA8/disk2]:2048;
disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_QdvzA8/disk1,id1:path1]:2048
I0206 09:34:16.718006  6609 hierarchical.cpp:1192] Recovered cpus(allocated: default-role):2;
mem(allocated: default-role):2048; ports(allocated: default-role):[31000-32000]; disk(allocated:
default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_QdvzA8/disk2]:2048;
disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_QdvzA8/disk1,id1:path1]:2048
(total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_QdvzA8/disk2]:2048;
disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_PreparePersistentVolume_3_QdvzA8/disk1,id1:path1]:2048,
allocated: {}) on agent 7b59cc87-bed8-427c-8d30-e44309484ca3-S0 from framework 7b59cc87-bed8-427c-8d30-e44309484ca3-0000
I0206 09:34:16.718191  6609 hierarchical.cpp:1238] Framework 7b59cc87-bed8-427c-8d30-e44309484ca3-0000
filtered agent 7b59cc87-bed8-427c-8d30-e44309484ca3-S0 for 5secs
I0206 09:34:16.718717  6586 sched.cpp:2009] Asked to stop the driver
I0206 09:34:16.718909  6601 sched.cpp:1191] Stopping framework 7b59cc87-bed8-427c-8d30-e44309484ca3-0000
I0206 09:34:16.719274  6605 master.cpp:9488] Processing TEARDOWN call for framework 7b59cc87-bed8-427c-8d30-e44309484ca3-0000
(default) at scheduler-1be756eb-5efc-45cb-95ff-63640e49a688@172.17.0.4:38512
I0206 09:34:16.719327  6605 master.cpp:9500] Removing framework 7b59cc87-bed8-427c-8d30-e44309484ca3-0000
(default) at scheduler-1be756eb-5efc-45cb-95ff-63640e49a688@172.17.0.4:38512
I0206 09:34:16.719350  6605 master.cpp:3239] Deactivating framework 7b59cc87-bed8-427c-8d30-e44309484ca3-0000
(default) at scheduler-1be756eb-5efc-45cb-95ff-63640e49a688@172.17.0.4:38512
I0206 09:34:16.719509  6594 hierarchical.cpp:405] Deactivated framework 7b59cc87-bed8-427c-8d30-e44309484ca3-0000
I0206 09:34:16.719619  6591 slave.cpp:3454] Asked to shut down framework 7b59cc87-bed8-427c-8d30-e44309484ca3-0000
by master@172.17.0.4:38512
I0206 09:34:16.719683  6591 slave.cpp:3469] Cannot shut down unknown framework 7b59cc87-bed8-427c-8d30-e44309484ca3-0000
I0206 09:34:16.720276  6606 hierarchical.cpp:344] Removed framework 7b59cc87-bed8-427c-8d30-e44309484ca3-0000
I0206 09:34:16.720284  6602 slave.cpp:931] Agent terminating
I0206 09:34:16.720660  6607 master.cpp:1307] Agent 7b59cc87-bed8-427c-8d30-e44309484ca3-S0
at slave(857)@172.17.0.4:38512 (4cb9abc5a66d) disconnected
I0206 09:34:16.720710  6607 master.cpp:3276] Disconnecting agent 7b59cc87-bed8-427c-8d30-e44309484ca3-S0
at slave(857)@172.17.0.4:38512 (4cb9abc5a66d)
I0206 09:34:16.720803  6607 master.cpp:3295] Deactivating agent 7b59cc87-bed8-427c-8d30-e44309484ca3-S0
at slave(857)@172.17.0.4:38512 (4cb9abc5a66d)
I0206 09:34:16.721048  6587 hierarchical.cpp:766] Agent 7b59cc87-bed8-427c-8d30-e44309484ca3-S0
deactivated
I0206 09:34:16.732723  6586 master.cpp:1149] Master terminating
I0206 09:34:16.734148  6603 hierarchical.cpp:609] Removed agent 7b59cc87-bed8-427c-8d30-e44309484ca3-S0
[       OK ] DiskResource/PersistentVolumeTest.PreparePersistentVolume/3 (124 ms)
[ RUN      ] DiskResource/PersistentVolumeTest.MasterFailover/0
I0206 09:34:16.743494  6586 cluster.cpp:172] Creating default 'local' authorizer
I0206 09:34:16.748158  6603 master.cpp:458] Master 50193fc6-491d-4e24-b08b-e598d81b3fdd (4cb9abc5a66d)
started on 172.17.0.4:38512
I0206 09:34:16.748190  6603 master.cpp:460] Flags at startup: --acls="" --agent_ping_timeout="15secs"
--agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF"
--authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true"
--authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5"
--authorizers="local" --credentials="/tmp/Jqr8Eh/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_unreachable_tasks_per_framework="1000" --port="5050"
--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"
--root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-1.6.0/_inst/share/mesos/webui"
--work_dir="/tmp/Jqr8Eh/master" --zk_session_timeout="10secs"
I0206 09:34:16.748580  6603 master.cpp:509] Master only allowing authenticated frameworks
to register
I0206 09:34:16.748594  6603 master.cpp:515] Master only allowing authenticated agents to register
I0206 09:34:16.748605  6603 master.cpp:521] Master only allowing authenticated HTTP frameworks
to register
I0206 09:34:16.748616  6603 credentials.hpp:37] Loading credentials for authentication from
'/tmp/Jqr8Eh/credentials'
I0206 09:34:16.748973  6603 master.cpp:565] Using default 'crammd5' authenticator
I0206 09:34:16.749167  6603 http.cpp:1045] Creating default 'basic' HTTP authenticator for
realm 'mesos-master-readonly'
I0206 09:34:16.749372  6603 http.cpp:1045] Creating default 'basic' HTTP authenticator for
realm 'mesos-master-readwrite'
I0206 09:34:16.749531  6603 http.cpp:1045] Creating default 'basic' HTTP authenticator for
realm 'mesos-master-scheduler'
I0206 09:34:16.749683  6603 master.cpp:644] Authorization enabled
I0206 09:34:16.749863  6606 hierarchical.cpp:175] Initialized hierarchical allocator process
I0206 09:34:16.749899  6608 whitelist_watcher.cpp:77] No whitelist given
I0206 09:34:16.753623  6609 master.cpp:2133] Elected as the leading master!
I0206 09:34:16.753685  6609 master.cpp:1692] Recovering from registrar
I0206 09:34:16.753928  6601 registrar.cpp:347] Recovering registrar
I0206 09:34:16.754844  6601 registrar.cpp:391] Successfully fetched the registry (0B) in 860160ns
I0206 09:34:16.754999  6601 registrar.cpp:495] Applied 1 operations in 42481ns; attempting
to update the registry
I0206 09:34:16.755784  6601 registrar.cpp:552] Successfully updated the registry in 705024ns
I0206 09:34:16.755956  6601 registrar.cpp:424] Successfully recovered registrar
I0206 09:34:16.756510  6597 master.cpp:1806] Recovered 0 agents from the registry (135B);
allowing 10mins for agents to re-register
I0206 09:34:16.756561  6594 hierarchical.cpp:213] Skipping recovery of hierarchical allocator:
nothing to recover
W0206 09:34:16.763990  6586 process.cpp:2805] Attempted to spawn already running process files@172.17.0.4:38512
I0206 09:34:16.765151  6586 containerizer.cpp:304] Using isolation { environment_secret, posix/cpu,
posix/mem, filesystem/posix, network/cni }
W0206 09:34:16.765803  6586 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires
root privileges
W0206 09:34:16.765960  6586 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires
root privileges
I0206 09:34:16.766006  6586 provisioner.cpp:299] Using default backend 'copy'
I0206 09:34:16.768438  6586 cluster.cpp:460] Creating default 'local' authorizer
I0206 09:34:16.771430  6594 slave.cpp:262] Mesos agent started on (858)@172.17.0.4:38512
I0206 09:34:16.771456  6594 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"
--appc_store_dir="/tmp/DiskResource_PersistentVolumeTest_MasterFailover_0_Q6AsIm/store/appc"
--authenticate_http_readonly="true" --authenticate_http_readwrite="false" --authenticatee="crammd5"
--authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false"
--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/DiskResource_PersistentVolumeTest_MasterFailover_0_Q6AsIm/credential"
--default_role="*" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins"
--docker="docker" --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/DiskResource_PersistentVolumeTest_MasterFailover_0_Q6AsIm/store/docker"
--docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false"
--executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs"
--fetcher_cache_dir="/tmp/DiskResource_PersistentVolumeTest_MasterFailover_0_Q6AsIm/fetch"
--fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1"
--hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/DiskResource_PersistentVolumeTest_MasterFailover_0_Q6AsIm/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem"
--launcher="posix" --launcher_dir="/mesos/mesos-1.6.0/_build/src" --logbufsecs="0" --logging_level="INFO"
--max_completed_executors_per_framework="150" --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="[{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":2048.0},"type":"SCALAR"},{"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":4096.0},"type":"SCALAR"}]"
--revocable_cpu_low_priority="true" --runtime_dir="/tmp/DiskResource_PersistentVolumeTest_MasterFailover_0_Q6AsIm"
--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/DiskResource_PersistentVolumeTest_MasterFailover_0_jzN40k"
--zk_session_timeout="10secs"
I0206 09:34:16.771904  6594 credentials.hpp:86] Loading credential for authentication from
'/tmp/DiskResource_PersistentVolumeTest_MasterFailover_0_Q6AsIm/credential'
I0206 09:34:16.772061  6594 slave.cpp:295] Agent using credential for: test-principal
I0206 09:34:16.772086  6594 credentials.hpp:37] Loading credentials for authentication from
'/tmp/DiskResource_PersistentVolumeTest_MasterFailover_0_Q6AsIm/http_credentials'
W0206 09:34:16.772157  6586 process.cpp:2805] Attempted to spawn already running process version@172.17.0.4:38512
I0206 09:34:16.772287  6594 http.cpp:1045] Creating default 'basic' HTTP authenticator for
realm 'mesos-agent-readonly'
I0206 09:34:16.773080  6586 sched.cpp:232] Version: 1.6.0
I0206 09:34:16.773747  6610 sched.cpp:336] New master detected at master@172.17.0.4:38512
I0206 09:34:16.773893  6610 sched.cpp:396] Authenticating with master master@172.17.0.4:38512
I0206 09:34:16.773921  6610 sched.cpp:403] Using default CRAM-MD5 authenticatee
I0206 09:34:16.774296  6600 authenticatee.cpp:121] Creating new client SASL connection
I0206 09:34:16.774332  6594 slave.cpp:612] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":2048.0},"type":"SCALAR"},{"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":4096.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I0206 09:34:16.774567  6594 slave.cpp:620] Agent attributes: [  ]
I0206 09:34:16.774585  6594 slave.cpp:629] Agent hostname: 4cb9abc5a66d
I0206 09:34:16.774621  6596 master.cpp:8978] Authenticating scheduler-dff9a7e1-6611-4d0b-a2a9-a5997c3613be@172.17.0.4:38512
I0206 09:34:16.774752  6605 task_status_update_manager.cpp:181] Pausing sending task status
updates
I0206 09:34:16.774797  6591 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1510)@172.17.0.4:38512
I0206 09:34:16.775121  6601 authenticator.cpp:98] Creating new server SASL connection
I0206 09:34:16.775418  6597 authenticatee.cpp:213] Received SASL authentication mechanisms:
CRAM-MD5
I0206 09:34:16.775454  6597 authenticatee.cpp:239] Attempting to authenticate with mechanism
'CRAM-MD5'
I0206 09:34:16.775600  6595 authenticator.cpp:204] Received SASL authentication start
I0206 09:34:16.775676  6595 authenticator.cpp:326] Authentication requires more steps
I0206 09:34:16.775800  6606 authenticatee.cpp:259] Received SASL authentication step
I0206 09:34:16.775951  6607 authenticator.cpp:232] Received SASL authentication step
I0206 09:34:16.775992  6607 auxprop.cpp:109] Request to lookup properties for user: 'test-principal'
realm: '4cb9abc5a66d' server FQDN: '4cb9abc5a66d' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0206 09:34:16.776008  6607 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0206 09:34:16.776062  6607 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0206 09:34:16.776094  6607 auxprop.cpp:109] Request to lookup properties for user: 'test-principal'
realm: '4cb9abc5a66d' server FQDN: '4cb9abc5a66d' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0206 09:34:16.776108  6607 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since
SASL_AUXPROP_AUTHZID == true
I0206 09:34:16.776116  6607 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5'
since SASL_AUXPROP_AUTHZID == true
I0206 09:34:16.776136  6607 authenticator.cpp:318] Authentication success
I0206 09:34:16.776233  6603 authenticatee.cpp:299] Authentication success
I0206 09:34:16.776361  6602 master.cpp:9008] Successfully authenticated principal 'test-principal'
at scheduler-dff9a7e1-6611-4d0b-a2a9-a5997c3613be@172.17.0.4:38512
I0206 09:34:16.776489  6589 state.cpp:66] Recovering state from '/tmp/DiskResource_PersistentVolumeTest_MasterFailover_0_jzN40k/meta'
I0206 09:34:16.776598  6593 sched.cpp:502] Successfully authenticated with master master@172.17.0.4:38512
I0206 09:34:16.776609  6587 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1510)@172.17.0.4:38512
I0206 09:34:16.776630  6593 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.4:38512
I0206 09:34:16.776760  6593 sched.cpp:857] Will retry registration in 195.337966ms if necessary
I0206 09:34:16.776872  6605 task_status_update_manager.cpp:207] Recovering task status update
manager
I0206 09:34:16.777019  6600 master.cpp:2869] Received SUBSCRIBE call for framework 'default'
at scheduler-dff9a7e1-6611-4d0b-a2a9-a5997c3613be@172.17.0.4:38512
I0206 09:34:16.777115  6600 master.cpp:2198] Authorizing framework principal 'test-principal'
to receive offers for roles '{ default-role }'
I0206 09:34:16.777133  6591 containerizer.cpp:674] Recovering containerizer
I0206 09:34:16.777770  6597 master.cpp:2949] Subscribing framework default with checkpointing
disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0206 09:34:16.777995  6597 master.cpp:9199] Adding framework 50193fc6-491d-4e24-b08b-e598d81b3fdd-0000
(default) at scheduler-dff9a7e1-6611-4d0b-a2a9-a5997c3613be@172.17.0.4:38512 with roles {
 } suppressed
I0206 09:34:16.778515  6610 sched.cpp:751] Framework registered with 50193fc6-491d-4e24-b08b-e598d81b3fdd-0000
I0206 09:34:16.778576  6610 sched.cpp:765] Scheduler::registered took 27162ns
I0206 09:34:16.778692  6598 hierarchical.cpp:297] Added framework 50193fc6-491d-4e24-b08b-e598d81b3fdd-0000
I0206 09:34:16.778759  6589 provisioner.cpp:495] Provisioner recovery complete
I0206 09:34:16.778975  6598 hierarchical.cpp:1517] Performed allocation for 0 agents in 99733ns
I0206 09:34:16.779121  6599 slave.cpp:6824] Finished recovery
I0206 09:34:16.779965  6604 task_status_update_manager.cpp:181] Pausing sending task status
updates
I0206 09:34:16.779965  6600 slave.cpp:1146] New master detected at master@172.17.0.4:38512
I0206 09:34:16.780062  6600 slave.cpp:1201] Detecting new master
I0206 09:34:16.788776  6595 slave.cpp:1228] Authenticating with master master@172.17.0.4:38512
I0206 09:34:16.788902  6595 slave.cpp:1237] Using default CRAM-MD5 authenticatee
I0206 09:34:16.789180  6608 authenticatee.cpp:121] Creating new client SASL connection
I0206 09:34:16.789423  6606 master.cpp:8978] Authenticating slave(858)@172.17.0.4:38512
I0206 09:34:16.789561  6603 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1511)@172.17.0.4:38512
I0206 09:34:16.789798  6591 authenticator.cpp:98] Creating new server SASL connection
I0206 09:34:16.790024  6590 authenticatee.cpp:213] Received SASL authentication mechanisms:
CRAM-MD5
I0206 09:34:16.790052  6590 authenticatee.cpp:239] Attempting to authenticate with mechanism
'CRAM-MD5'
I0206 09:34:16.790163  6602 authenticator.cpp:204] Received SASL authentication start
I0206 09:34:16.790231  6602 authenticator.cpp:326] Authentication requires more steps
I0206 09:34:16.790340  6592 authenticatee.cpp:259] Received SASL authentication step
I0206 09:34:16.790457  6607 authenticator.cpp:232] Received SASL authentication step
I0206 09:34:16.790488  6607 auxprop.cpp:109] Request to lookup properties for user: 'test-principal'
realm: '4cb9abc5a66d' server FQDN: '4cb9abc5a66d' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0206 09:34:16.790503  6607 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0206 09:34:16.790544  6607 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0206 09:34:16.790575  6607 auxprop.cpp:109] Request to lookup properties for user: 'test-principal'
realm: '4cb9abc5a66d' server FQDN: '4cb9abc5a66d' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0206 09:34:16.790587  6607 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since
SASL_AUXPROP_AUTHZID == true
I0206 09:34:16.790597  6607 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5'
since SASL_AUXPROP_AUTHZID == true
I0206 09:34:16.790614  6607 authenticator.cpp:318] Authentication success
I0206 09:34:16.790736  6597 authenticatee.cpp:299] Authentication success
I0206 09:34:16.790762  6610 master.cpp:9008] Successfully authenticated principal 'test-principal'
at slave(858)@172.17.0.4:38512
I0206 09:34:16.790791  6587 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1511)@172.17.0.4:38512
I0206 09:34:16.791049  6594 slave.cpp:1320] Successfully authenticated with master master@172.17.0.4:38512
I0206 09:34:16.791366  6594 slave.cpp:1766] Will retry registration in 15.79314ms if necessary
I0206 09:34:16.791585  6599 master.cpp:6013] Received register agent message from slave(858)@172.17.0.4:38512
(4cb9abc5a66d)
I0206 09:34:16.791929  6599 master.cpp:3793] Authorizing agent providing resources 'cpus:2;
mem:2048; disk(reservations: [(STATIC,default-role)]):4096; ports:[31000-32000]' with principal
'test-principal'
I0206 09:34:16.792311  6599 master.cpp:3573] Authorizing principal 'test-principal' to reserve
resources 'cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)]):4096; ports:[31000-32000]'
I0206 09:34:16.793151  6608 master.cpp:6084] Authorized registration of agent at slave(858)@172.17.0.4:38512
(4cb9abc5a66d)
I0206 09:34:16.793241  6608 master.cpp:6195] Registering agent at slave(858)@172.17.0.4:38512
(4cb9abc5a66d) with id 50193fc6-491d-4e24-b08b-e598d81b3fdd-S0
I0206 09:34:16.793857  6603 registrar.cpp:495] Applied 1 operations in 177012ns; attempting
to update the registry
I0206 09:34:16.794500  6603 registrar.cpp:552] Successfully updated the registry in 574976ns
I0206 09:34:16.794675  6607 master.cpp:6243] Admitted agent 50193fc6-491d-4e24-b08b-e598d81b3fdd-S0
at slave(858)@172.17.0.4:38512 (4cb9abc5a66d)
I0206 09:34:16.795421  6607 master.cpp:6292] Registered agent 50193fc6-491d-4e24-b08b-e598d81b3fdd-S0
at slave(858)@172.17.0.4:38512 (4cb9abc5a66d) with cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)]):4096;
ports:[31000-32000]
I0206 09:34:16.795506  6598 slave.cpp:1367] Registered with master master@172.17.0.4:38512;
given agent ID 50193fc6-491d-4e24-b08b-e598d81b3fdd-S0
I0206 09:34:16.795631  6589 task_status_update_manager.cpp:188] Resuming sending task status
updates
I0206 09:34:16.795882  6598 slave.cpp:1387] Checkpointing SlaveInfo to '/tmp/DiskResource_PersistentVolumeTest_MasterFailover_0_jzN40k/meta/slaves/50193fc6-491d-4e24-b08b-e598d81b3fdd-S0/slave.info'
I0206 09:34:16.795961  6597 hierarchical.cpp:574] Added agent 50193fc6-491d-4e24-b08b-e598d81b3fdd-S0
(4cb9abc5a66d) with cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)]):4096; ports:[31000-32000]
(allocated: {})
I0206 09:34:16.796537  6598 slave.cpp:1434] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"8EZoNBu8Que1yimhOm4MeQ=="},"slave_id":{"value":"50193fc6-491d-4e24-b08b-e598d81b3fdd-S0"},"update_oversubscribed_resources":true}
I0206 09:34:16.797036  6598 master.cpp:7235] Received update of agent 50193fc6-491d-4e24-b08b-e598d81b3fdd-S0
at slave(858)@172.17.0.4:38512 (4cb9abc5a66d) with total oversubscribed resources {}
I0206 09:34:16.797363  6598 master.cpp:7329] Ignoring update on agent 50193fc6-491d-4e24-b08b-e598d81b3fdd-S0
at slave(858)@172.17.0.4:38512 (4cb9abc5a66d) as it reports no changes
I0206 09:34:16.797713  6597 hierarchical.cpp:1517] Performed allocation for 1 agents in 1.547305ms
I0206 09:34:16.798279  6594 master.cpp:8808] Sending 1 offers to framework 50193fc6-491d-4e24-b08b-e598d81b3fdd-0000
(default) at scheduler-dff9a7e1-6611-4d0b-a2a9-a5997c3613be@172.17.0.4:38512
I0206 09:34:16.798821  6596 sched.cpp:921] Scheduler::resourceOffers took 121809ns
I0206 09:34:16.800843  6606 master.cpp:10716] Removing offer 50193fc6-491d-4e24-b08b-e598d81b3fdd-O0
I0206 09:34:16.801244  6606 master.cpp:4220] Processing ACCEPT call for offers: [ 50193fc6-491d-4e24-b08b-e598d81b3fdd-O0
] on agent 50193fc6-491d-4e24-b08b-e598d81b3fdd-S0 at slave(858)@172.17.0.4:38512 (4cb9abc5a66d)
for framework 50193fc6-491d-4e24-b08b-e598d81b3fdd-0000 (default) at scheduler-dff9a7e1-6611-4d0b-a2a9-a5997c3613be@172.17.0.4:38512
I0206 09:34:16.801401  6606 master.cpp:3708] Authorizing principal 'test-principal' to create
volumes '[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
write /dev/stdout: resource temporarily unavailable
+ docker rmi --force mesos-1517904794-10266
Untagged: mesos-1517904794-10266:latest
Build step 'Execute shell' marked build as failure


Mime
View raw message