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 2016/03/03 04:05:05 UTC
Build failed in Jenkins: Mesos » gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(docker||Hadoop)&&(!ubuntu-us1) #1763
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)/1763/changes>
Changes:
[joris.van.remoortere] Fixed updating slave's version after re-registering.
[yujie.jay] Introduced copy fetcher plugin for file URIs.
[yujie.jay] Added support for file URI in Appc fetcher.
[yujie.jay] Added test for Appc image fetcher.
[vinodkone] Removed 'Subscribe.force' field from v1 Scheduler API.
[vinodkone] Updated master to ignore 'Subscribe.force' for HTTP framework.
[vinodkone] Updated the CHANGELOG and doc about 'subscribe.force' field removal.
------------------------------------------
[...truncated 73495 lines...]
I0303 03:04:48.994376 772 slave.cpp:796] New master detected at master@172.17.0.1:51078
I0303 03:04:48.994494 772 slave.cpp:859] Authenticating with master master@172.17.0.1:51078
I0303 03:04:48.994513 772 slave.cpp:864] Using default CRAM-MD5 authenticatee
I0303 03:04:48.994662 772 slave.cpp:832] Detecting new master
I0303 03:04:48.994719 766 authenticatee.cpp:121] Creating new client SASL connection
I0303 03:04:48.994807 772 slave.cpp:4751] Received oversubscribable resources from the resource estimator
I0303 03:04:48.994995 772 master.cpp:5495] Authenticating slave(131)@172.17.0.1:51078
I0303 03:04:48.995131 759 authenticator.cpp:413] Starting authentication session for crammd5_authenticatee(323)@172.17.0.1:51078
I0303 03:04:48.995462 759 authenticator.cpp:98] Creating new server SASL connection
I0303 03:04:48.995677 759 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
I0303 03:04:48.995708 759 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I0303 03:04:48.995787 759 authenticator.cpp:203] Received SASL authentication start
I0303 03:04:48.995865 759 authenticator.cpp:325] Authentication requires more steps
I0303 03:04:48.995992 764 authenticatee.cpp:258] Received SASL authentication step
I0303 03:04:48.996114 764 authenticator.cpp:231] Received SASL authentication step
I0303 03:04:48.996153 764 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: '78cf8e278a74' server FQDN: '78cf8e278a74' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0303 03:04:48.996170 764 auxprop.cpp:179] Looking up auxiliary property '*userPassword'
I0303 03:04:48.996219 764 auxprop.cpp:179] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0303 03:04:48.996239 764 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: '78cf8e278a74' server FQDN: '78cf8e278a74' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0303 03:04:48.996248 764 auxprop.cpp:129] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0303 03:04:48.996253 764 auxprop.cpp:129] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0303 03:04:48.996268 764 authenticator.cpp:317] Authentication success
I0303 03:04:48.996412 764 authenticatee.cpp:298] Authentication success
I0303 03:04:48.996486 764 master.cpp:5525] Successfully authenticated principal 'test-principal' at slave(131)@172.17.0.1:51078
I0303 03:04:48.996551 764 authenticator.cpp:431] Authentication session cleanup for crammd5_authenticatee(323)@172.17.0.1:51078
I0303 03:04:48.997041 764 slave.cpp:927] Successfully authenticated with master master@172.17.0.1:51078
I0303 03:04:48.997202 764 slave.cpp:1321] Will retry registration in 5.353099ms if necessary
I0303 03:04:48.997524 764 master.cpp:4206] Registering slave at slave(131)@172.17.0.1:51078 (78cf8e278a74) with id 578f7379-329c-47de-a100-779d5b3d3b75-S0
I0303 03:04:48.998088 764 registrar.cpp:439] Applied 1 operations in 69634ns; attempting to update the 'registry'
I0303 03:04:48.999096 771 log.cpp:683] Attempting to append 339 bytes to the log
I0303 03:04:48.999243 772 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3
I0303 03:04:49.000059 765 replica.cpp:537] Replica received write request for position 3 from (5097)@172.17.0.1:51078
I0303 03:04:49.000351 765 leveldb.cpp:341] Persisting action (358 bytes) to leveldb took 242967ns
I0303 03:04:49.000378 765 replica.cpp:712] Persisted action at 3
I0303 03:04:49.001006 758 replica.cpp:691] Replica received learned notice for position 3 from @0.0.0.0:0
I0303 03:04:49.001480 758 leveldb.cpp:341] Persisting action (360 bytes) to leveldb took 444704ns
I0303 03:04:49.001505 758 replica.cpp:712] Persisted action at 3
I0303 03:04:49.001528 758 replica.cpp:697] Replica learned APPEND action at position 3
I0303 03:04:49.003041 771 registrar.cpp:484] Successfully updated the 'registry' in 4.877056ms
I0303 03:04:49.003355 758 log.cpp:702] Attempting to truncate the log to 3
I0303 03:04:49.003540 771 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 4
I0303 03:04:49.004076 764 slave.cpp:3482] Received ping from slave-observer(132)@172.17.0.1:51078
I0303 03:04:49.004254 758 replica.cpp:537] Replica received write request for position 4 from (5098)@172.17.0.1:51078
I0303 03:04:49.004469 765 slave.cpp:1321] Will retry registration in 4.945072ms if necessary
I0303 03:04:49.004565 764 hierarchical.cpp:473] Added slave 578f7379-329c-47de-a100-779d5b3d3b75-S0 (78cf8e278a74) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: )
I0303 03:04:49.004784 764 hierarchical.cpp:1453] No resources available to allocate!
I0303 03:04:49.004945 764 hierarchical.cpp:1150] Performed allocation for slave 578f7379-329c-47de-a100-779d5b3d3b75-S0 in 316211ns
I0303 03:04:49.004871 765 slave.cpp:971] Registered with master master@172.17.0.1:51078; given slave ID 578f7379-329c-47de-a100-779d5b3d3b75-S0
I0303 03:04:49.004858 758 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 559775ns
I0303 03:04:49.005283 758 replica.cpp:712] Persisted action at 4
I0303 03:04:49.005163 765 fetcher.cpp:81] Clearing fetcher cache
I0303 03:04:49.005621 758 status_update_manager.cpp:181] Resuming sending status updates
I0303 03:04:49.005730 765 slave.cpp:994] Checkpointing SlaveInfo to '/tmp/MasterSlaveReconciliationTest_ReconcileRace_zpUOZt/meta/slaves/578f7379-329c-47de-a100-779d5b3d3b75-S0/slave.info'
I0303 03:04:49.006211 765 slave.cpp:1030] Forwarding total oversubscribed resources
I0303 03:04:49.006341 765 replica.cpp:691] Replica received learned notice for position 4 from @0.0.0.0:0
I0303 03:04:49.004539 759 master.cpp:4274] Registered slave 578f7379-329c-47de-a100-779d5b3d3b75-S0 at slave(131)@172.17.0.1:51078 (78cf8e278a74) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0303 03:04:49.006587 739 sched.cpp:222] Version: 0.28.0
I0303 03:04:49.006768 765 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 396726ns
I0303 03:04:49.006865 765 leveldb.cpp:399] Deleting ~2 keys from leveldb took 65042ns
I0303 03:04:49.006896 765 replica.cpp:712] Persisted action at 4
I0303 03:04:49.006927 765 replica.cpp:697] Replica learned TRUNCATE action at position 4
I0303 03:04:49.007292 762 sched.cpp:326] New master detected at master@172.17.0.1:51078
I0303 03:04:49.007369 767 slave.cpp:796] New master detected at master@172.17.0.1:51078
I0303 03:04:49.007390 762 sched.cpp:382] Authenticating with master master@172.17.0.1:51078
I0303 03:04:49.007411 762 sched.cpp:389] Using default CRAM-MD5 authenticatee
I0303 03:04:49.007453 767 slave.cpp:859] Authenticating with master master@172.17.0.1:51078
I0303 03:04:49.007479 767 slave.cpp:864] Using default CRAM-MD5 authenticatee
I0303 03:04:49.007627 767 slave.cpp:832] Detecting new master
I0303 03:04:49.007869 770 status_update_manager.cpp:174] Pausing sending status updates
I0303 03:04:49.007899 760 authenticatee.cpp:121] Creating new client SASL connection
I0303 03:04:49.007961 772 authenticatee.cpp:121] Creating new client SASL connection
I0303 03:04:49.008075 759 master.cpp:4176] Slave 578f7379-329c-47de-a100-779d5b3d3b75-S0 at slave(131)@172.17.0.1:51078 (78cf8e278a74) already registered, resending acknowledgement
I0303 03:04:49.008270 768 slave.cpp:971] Registered with master master@172.17.0.1:51078; given slave ID 578f7379-329c-47de-a100-779d5b3d3b75-S0
I0303 03:04:49.008296 759 master.cpp:4618] Received update of slave 578f7379-329c-47de-a100-779d5b3d3b75-S0 at slave(131)@172.17.0.1:51078 (78cf8e278a74) with total oversubscribed resources
I0303 03:04:49.008417 768 fetcher.cpp:81] Clearing fetcher cache
I0303 03:04:49.008586 759 master.cpp:5495] Authenticating scheduler-9aeb03b2-2ebb-480c-ac23-a5b332fe08be@172.17.0.1:51078
I0303 03:04:49.008766 762 status_update_manager.cpp:181] Resuming sending status updates
I0303 03:04:49.008837 762 authenticator.cpp:413] Starting authentication session for crammd5_authenticatee(324)@172.17.0.1:51078
I0303 03:04:49.008855 759 master.cpp:5495] Authenticating slave(131)@172.17.0.1:51078
I0303 03:04:49.009063 768 slave.cpp:994] Checkpointing SlaveInfo to '/tmp/MasterSlaveReconciliationTest_ReconcileRace_zpUOZt/meta/slaves/578f7379-329c-47de-a100-779d5b3d3b75-S0/slave.info'
I0303 03:04:49.009085 762 authenticator.cpp:413] Starting authentication session for crammd5_authenticatee(325)@172.17.0.1:51078
I0303 03:04:49.009104 759 authenticator.cpp:98] Creating new server SASL connection
I0303 03:04:49.009338 761 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
I0303 03:04:49.009373 761 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I0303 03:04:49.009378 759 authenticator.cpp:98] Creating new server SASL connection
I0303 03:04:49.009488 770 authenticator.cpp:203] Received SASL authentication start
I0303 03:04:49.009560 761 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
I0303 03:04:49.009562 770 authenticator.cpp:325] Authentication requires more steps
I0303 03:04:49.009587 761 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I0303 03:04:49.009663 762 authenticator.cpp:203] Received SASL authentication start
I0303 03:04:49.009737 762 authenticator.cpp:325] Authentication requires more steps
I0303 03:04:49.009855 768 slave.cpp:1030] Forwarding total oversubscribed resources
I0303 03:04:49.009881 762 authenticatee.cpp:258] Received SASL authentication step
I0303 03:04:49.009980 767 hierarchical.cpp:531] Slave 578f7379-329c-47de-a100-779d5b3d3b75-S0 (78cf8e278a74) updated with oversubscribed resources (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: )
I0303 03:04:49.010027 762 authenticator.cpp:231] Received SASL authentication step
I0303 03:04:49.010028 759 master.cpp:4618] Received update of slave 578f7379-329c-47de-a100-779d5b3d3b75-S0 at slave(131)@172.17.0.1:51078 (78cf8e278a74) with total oversubscribed resources
I0303 03:04:49.010057 762 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: '78cf8e278a74' server FQDN: '78cf8e278a74' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0303 03:04:49.010087 762 auxprop.cpp:179] Looking up auxiliary property '*userPassword'
I0303 03:04:49.010135 762 auxprop.cpp:179] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0303 03:04:49.010139 767 hierarchical.cpp:1453] No resources available to allocate!
I0303 03:04:49.010162 767 hierarchical.cpp:1150] Performed allocation for slave 578f7379-329c-47de-a100-779d5b3d3b75-S0 in 135877ns
I0303 03:04:49.010164 762 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: '78cf8e278a74' server FQDN: '78cf8e278a74' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0303 03:04:49.010221 762 auxprop.cpp:129] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0303 03:04:49.010233 762 auxprop.cpp:129] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0303 03:04:49.010253 762 authenticator.cpp:317] Authentication success
I0303 03:04:49.010252 767 authenticatee.cpp:258] Received SASL authentication step
I0303 03:04:49.010350 759 authenticatee.cpp:298] Authentication success
I0303 03:04:49.010375 767 authenticator.cpp:231] Received SASL authentication step
I0303 03:04:49.010403 767 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: '78cf8e278a74' server FQDN: '78cf8e278a74' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0303 03:04:49.010417 767 auxprop.cpp:179] Looking up auxiliary property '*userPassword'
I0303 03:04:49.010424 762 master.cpp:5525] Successfully authenticated principal 'test-principal' at slave(131)@172.17.0.1:51078
I0303 03:04:49.010502 759 authenticator.cpp:431] Authentication session cleanup for crammd5_authenticatee(325)@172.17.0.1:51078
I0303 03:04:49.010635 767 auxprop.cpp:179] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0303 03:04:49.010713 761 slave.cpp:927] Successfully authenticated with master master@172.17.0.1:51078
I0303 03:04:49.010726 769 hierarchical.cpp:531] Slave 578f7379-329c-47de-a100-779d5b3d3b75-S0 (78cf8e278a74) updated with oversubscribed resources (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: )
I0303 03:04:49.010864 767 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: '78cf8e278a74' server FQDN: '78cf8e278a74' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0303 03:04:49.010963 767 auxprop.cpp:129] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0303 03:04:49.010980 767 auxprop.cpp:129] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0303 03:04:49.011003 767 authenticator.cpp:317] Authentication success
I0303 03:04:49.010871 769 hierarchical.cpp:1453] No resources available to allocate!
I0303 03:04:49.011135 758 authenticatee.cpp:298] Authentication success
I0303 03:04:49.011173 767 master.cpp:5525] Successfully authenticated principal 'test-principal' at scheduler-9aeb03b2-2ebb-480c-ac23-a5b332fe08be@172.17.0.1:51078
I0303 03:04:49.011255 769 hierarchical.cpp:1150] Performed allocation for slave 578f7379-329c-47de-a100-779d5b3d3b75-S0 in 404363ns
I0303 03:04:49.011272 767 authenticator.cpp:431] Authentication session cleanup for crammd5_authenticatee(324)@172.17.0.1:51078
I0303 03:04:49.011554 758 sched.cpp:471] Successfully authenticated with master master@172.17.0.1:51078
I0303 03:04:49.011617 758 sched.cpp:776] Sending SUBSCRIBE call to master@172.17.0.1:51078
I0303 03:04:49.011734 758 sched.cpp:809] Will retry registration in 1.207562766secs if necessary
I0303 03:04:49.011865 766 master.cpp:2231] Received SUBSCRIBE call for framework 'default' at scheduler-9aeb03b2-2ebb-480c-ac23-a5b332fe08be@172.17.0.1:51078
I0303 03:04:49.011940 766 master.cpp:1750] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0303 03:04:49.012241 763 master.cpp:2302] Subscribing framework default with checkpointing disabled and capabilities [ ]
I0303 03:04:49.012753 758 hierarchical.cpp:265] Added framework 578f7379-329c-47de-a100-779d5b3d3b75-0000
I0303 03:04:49.012881 762 sched.cpp:703] Framework registered with 578f7379-329c-47de-a100-779d5b3d3b75-0000
I0303 03:04:49.012933 762 sched.cpp:717] Scheduler::registered took 26011ns
I0303 03:04:49.013535 758 hierarchical.cpp:1548] No inverse offers to send out!
I0303 03:04:49.013581 758 hierarchical.cpp:1130] Performed allocation for 1 slaves in 802143ns
I0303 03:04:49.013953 763 master.cpp:5324] Sending 1 offers to framework 578f7379-329c-47de-a100-779d5b3d3b75-0000 (default) at scheduler-9aeb03b2-2ebb-480c-ac23-a5b332fe08be@172.17.0.1:51078
I0303 03:04:49.014400 770 sched.cpp:873] Scheduler::resourceOffers took 86522ns
I0303 03:04:49.952085 763 hierarchical.cpp:1453] No resources available to allocate!
I0303 03:04:49.952172 763 hierarchical.cpp:1548] No inverse offers to send out!
I0303 03:04:49.952208 763 hierarchical.cpp:1130] Performed allocation for 1 slaves in 375705ns
I0303 03:04:50.953461 765 hierarchical.cpp:1453] No resources available to allocate!
I0303 03:04:50.953544 765 hierarchical.cpp:1548] No inverse offers to send out!
I0303 03:04:50.953585 765 hierarchical.cpp:1130] Performed allocation for 1 slaves in 362430ns
I0303 03:04:51.955039 766 hierarchical.cpp:1453] No resources available to allocate!
I0303 03:04:51.955124 766 hierarchical.cpp:1548] No inverse offers to send out!
I0303 03:04:51.955168 766 hierarchical.cpp:1130] Performed allocation for 1 slaves in 391841ns
I0303 03:04:52.957010 764 hierarchical.cpp:1453] No resources available to allocate!
I0303 03:04:52.957113 764 hierarchical.cpp:1548] No inverse offers to send out!
I0303 03:04:52.957154 764 hierarchical.cpp:1130] Performed allocation for 1 slaves in 453110ns
I0303 03:04:53.958101 772 hierarchical.cpp:1453] No resources available to allocate!
I0303 03:04:53.958184 772 hierarchical.cpp:1548] No inverse offers to send out!
I0303 03:04:53.958227 772 hierarchical.cpp:1130] Performed allocation for 1 slaves in 368162ns
I0303 03:04:54.959012 773 hierarchical.cpp:1453] No resources available to allocate!
I0303 03:04:54.959097 773 hierarchical.cpp:1548] No inverse offers to send out!
I0303 03:04:54.959131 773 hierarchical.cpp:1130] Performed allocation for 1 slaves in 381736ns
I0303 03:04:55.960563 763 hierarchical.cpp:1453] No resources available to allocate!
I0303 03:04:55.960657 763 hierarchical.cpp:1548] No inverse offers to send out!
I0303 03:04:55.960696 763 hierarchical.cpp:1130] Performed allocation for 1 slaves in 399340ns
I0303 03:04:56.962375 760 hierarchical.cpp:1453] No resources available to allocate!
I0303 03:04:56.962484 760 hierarchical.cpp:1548] No inverse offers to send out!
I0303 03:04:56.962527 760 hierarchical.cpp:1130] Performed allocation for 1 slaves in 539612ns
I0303 03:04:57.963989 764 hierarchical.cpp:1453] No resources available to allocate!
I0303 03:04:57.964071 764 hierarchical.cpp:1548] No inverse offers to send out!
I0303 03:04:57.964121 764 hierarchical.cpp:1130] Performed allocation for 1 slaves in 354250ns
I0303 03:04:58.965107 770 hierarchical.cpp:1453] No resources available to allocate!
I0303 03:04:58.965186 770 hierarchical.cpp:1548] No inverse offers to send out!
I0303 03:04:58.965219 770 hierarchical.cpp:1130] Performed allocation for 1 slaves in 427251ns
I0303 03:04:59.966682 758 hierarchical.cpp:1453] No resources available to allocate!
I0303 03:04:59.966771 758 hierarchical.cpp:1548] No inverse offers to send out!
I0303 03:04:59.966812 758 hierarchical.cpp:1130] Performed allocation for 1 slaves in 420203ns
I0303 03:05:00.968307 761 hierarchical.cpp:1453] No resources available to allocate!
I0303 03:05:00.968384 761 hierarchical.cpp:1548] No inverse offers to send out!
I0303 03:05:00.968416 761 hierarchical.cpp:1130] Performed allocation for 1 slaves in 374809ns
I0303 03:05:01.969204 770 hierarchical.cpp:1453] No resources available to allocate!
I0303 03:05:01.969290 770 hierarchical.cpp:1548] No inverse offers to send out!
I0303 03:05:01.969327 770 hierarchical.cpp:1130] Performed allocation for 1 slaves in 361673ns
I0303 03:05:02.970410 761 hierarchical.cpp:1453] No resources available to allocate!
I0303 03:05:02.970484 761 hierarchical.cpp:1548] No inverse offers to send out!
I0303 03:05:02.970530 761 hierarchical.cpp:1130] Performed allocation for 1 slaves in 354773ns
I0303 03:05:03.971545 758 hierarchical.cpp:1453] No resources available to allocate!
I0303 03:05:03.971623 758 hierarchical.cpp:1548] No inverse offers to send out!
I0303 03:05:03.971668 758 hierarchical.cpp:1130] Performed allocation for 1 slaves in 334761ns
I0303 03:05:03.995404 766 slave.cpp:4737] Querying resource estimator for oversubscribable resources
I0303 03:05:03.995766 766 slave.cpp:4751] Received oversubscribable resources from the resource estimator
I0303 03:05:04.004984 766 slave.cpp:3482] Received ping from slave-observer(132)@172.17.0.1:51078
../../src/tests/master_slave_reconciliation_tests.cpp:302: Failure
Failed to wait 15secs for reregisterSlaveMessage
I0303 03:05:04.008863 766 master.cpp:1212] Framework 578f7379-329c-47de-a100-779d5b3d3b75-0000 (default) at scheduler-9aeb03b2-2ebb-480c-ac23-a5b332fe08be@172.17.0.1:51078 disconnected
I0303 03:05:04.008924 766 master.cpp:2527] Disconnecting framework 578f7379-329c-47de-a100-779d5b3d3b75-0000 (default) at scheduler-9aeb03b2-2ebb-480c-ac23-a5b332fe08be@172.17.0.1:51078
I0303 03:05:04.008967 766 master.cpp:2551] Deactivating framework 578f7379-329c-47de-a100-779d5b3d3b75-0000 (default) at scheduler-9aeb03b2-2ebb-480c-ac23-a5b332fe08be@172.17.0.1:51078
I0303 03:05:04.009332 764 hierarchical.cpp:375] Deactivated framework 578f7379-329c-47de-a100-779d5b3d3b75-0000
W0303 03:05:04.009747 766 master.hpp:1760] Master attempted to send message to disconnected framework 578f7379-329c-47de-a100-779d5b3d3b75-0000 (default) at scheduler-9aeb03b2-2ebb-480c-ac23-a5b332fe08be@172.17.0.1:51078
I0303 03:05:04.009889 766 master.cpp:1236] Giving framework 578f7379-329c-47de-a100-779d5b3d3b75-0000 (default) at scheduler-9aeb03b2-2ebb-480c-ac23-a5b332fe08be@172.17.0.1:51078 0ns to failover
I0303 03:05:04.010118 766 slave.cpp:785] Re-detecting master
I0303 03:05:04.010154 766 slave.cpp:832] Detecting new master
I0303 03:05:04.010120 771 hierarchical.cpp:890] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: ) on slave 578f7379-329c-47de-a100-779d5b3d3b75-S0 from framework 578f7379-329c-47de-a100-779d5b3d3b75-0000
F0303 03:05:04.010154 766 logging.cpp:64] RAW: Pure virtual method called
I0303 03:05:04.010231 771 status_update_manager.cpp:174] Pausing sending status updates
I0303 03:05:04.010478 739 master.cpp:1026] Master terminating
I0303 03:05:04.011008 767 hierarchical.cpp:505] Removed slave 578f7379-329c-47de-a100-779d5b3d3b75-S0
I0303 03:05:04.011143 767 hierarchical.cpp:326] Removed framework 578f7379-329c-47de-a100-779d5b3d3b75-0000
@ 0x2b406bca58a0 google::LogMessage::Fail()
@ 0x2b406bcaaf50 google::RawLog__()
@ 0x2b406adfdca6 __cxa_pure_virtual
@ 0x2b406b198815 mesos::internal::slave::Slave::detected()
@ 0x2b406b1f0d7f _ZZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS_6FutureI6OptionINS1_10MasterInfoEEEES9_EEvRKNS_3PIDIT_EEMSD_FvT0_ET1_ENKUlPNS_11ProcessBaseEE_clESM_
@ 0x2b406b227a64 _ZNSt17_Function_handlerIFvPN7process11ProcessBaseEEZNS0_8dispatchIN5mesos8internal5slave5SlaveERKNS0_6FutureI6OptionINS5_10MasterInfoEEEESD_EEvRKNS0_3PIDIT_EEMSH_FvT0_ET1_EUlS2_E_E9_M_invokeERKSt9_Any_dataS2_
@ 0x2b406bc24951 std::function<>::operator()()
@ 0x2b406bc0a981 process::ProcessBase::visit()
@ 0x2b406bc10a28 process::DispatchEvent::visit()
@ 0x9aa50c process::ProcessBase::serve()
@ 0x2b406bc06b64 process::ProcessManager::resume()
@ 0x2b406bc03c1c _ZZN7process14ProcessManager12init_threadsEvENKUlRKSt11atomic_boolE_clES3_
@ 0x2b406bc10214 _ZNSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS3_EEE6__callIvIEILm0EEEET_OSt5tupleIIDpT0_EESt12_Index_tupleIIXspT1_EEE
@ 0x2b406bc101c4 _ZNSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS3_EEEclIIEvEET0_DpOT_
@ 0x2b406bc10156 _ZNSt12_Bind_simpleIFSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS4_EEEvEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE
@ 0x2b406bc100ad _ZNSt12_Bind_simpleIFSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS4_EEEvEEclEv
@ 0x2b406bc10046 _ZNSt6thread5_ImplISt12_Bind_simpleIFSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS6_EEEvEEE6_M_runEv
@ 0x2b406d240a60 (unknown)
@ 0x2b406d9b7182 start_thread
@ 0x2b406dcc747d (unknown)
make[4]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[4]: *** [check-local] Aborted
make[3]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[3]: *** [check-am] Error 2
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.28.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1456972022-15392
Untagged: mesos-1456972022-15392:latest
Deleted: cfc3c130f7046691a67c5766e1626f73a9ada4801bd3ca93a462dc5f0d1e30c8
Deleted: 1d8351de33d1ba9556c71acc9a3fb77dbf9f00f573434b50cdb528721d794758
Deleted: ae0b9cda21f7d44f1786c4e4d51de826b724f0956b533e03645ba7c4ccf69ed6
Deleted: a48c04517d1fd36bfa22e96cb4edaea8a92983d2d109e24f36cd9483e68b90ac
Deleted: bb386af32c0273b723bd16a68a508fa115a73895353f4054defcce781fb3ec67
Deleted: 597281e9067ab428b8caea8432de8a66f746e05778b51ff0b245c8f888ff2d09
Deleted: 4f854819288a5e48eb87342f48dc78c0ffe3a6ee2b9631206cb7e194bbe07f42
Deleted: ba3e072060ffbb271572ca75bd96274407ec47015ddbdd735d39657840925cc0
Deleted: c23422d8b1113f2bc06bbb3ee0259eb01a598bd8fe1e5f683408c86de188f4e8
Deleted: c6bd028846fe9b0c533504fc663075dd19ab784f3c3bd0f58de3ec59e3079d2c
Deleted: aab729dfde9b29c51366628f873fbd4725b732ce846129d795c24884bac512ee
Deleted: 4ed6d0423681f2bc9bdad22d3a7b0cea7d627862674795a0ae47de7b79999150
Deleted: 6e70677ca19af2b67448247a5da45042c23e5f11e8c6158e45e2fa033267cd61
Deleted: 016e957cc06b9beb267eedf1c44b4413398b80953b9b80c6be2a6fc91f3502ce
Deleted: 5adc42149d872e3bde8abf917fc221940e44905b8b122e806282bae50d997c1f
Deleted: 3e5115ca143f8c203fabeb019665eb6fa4c1dc866407659d2c2afe41f4759d63
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos » gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(docker||Hadoop)&&(!ubuntu-us1) #1766
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)/1766/changes>
Build failed in Jenkins: Mesos » gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(docker||Hadoop)&&(!ubuntu-us1) #1765
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)/1765/changes>
Changes:
[joris.van.remoortere] Fixed virtual function shadowing in appc provision test.
------------------------------------------
[...truncated 171264 lines...]
I0303 07:46:27.070379 770 master.cpp:375] Master 6fd214c8-bcc7-4762-b908-21b6c08b6bc9 (e766e26128b8) started on 172.17.0.3:54257
I0303 07:46:27.070555 770 master.cpp:377] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/481i4s/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="100secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/481i4s/master" --zk_session_timeout="10secs"
I0303 07:46:27.071296 770 master.cpp:424] Master allowing unauthenticated frameworks to register
I0303 07:46:27.071370 770 master.cpp:427] Master only allowing authenticated slaves to register
I0303 07:46:27.071478 770 credentials.hpp:35] Loading credentials for authentication from '/tmp/481i4s/credentials'
I0303 07:46:27.071969 770 master.cpp:467] Using default 'crammd5' authenticator
I0303 07:46:27.072262 770 master.cpp:536] Using default 'basic' HTTP authenticator
I0303 07:46:27.072484 770 master.cpp:570] Authorization enabled
I0303 07:46:27.074409 759 hierarchical.cpp:144] Initialized hierarchical allocator process
I0303 07:46:27.074576 759 whitelist_watcher.cpp:77] No whitelist given
I0303 07:46:27.077095 770 master.cpp:1711] The newly elected leader is master@172.17.0.3:54257 with id 6fd214c8-bcc7-4762-b908-21b6c08b6bc9
I0303 07:46:27.077313 770 master.cpp:1724] Elected as the leading master!
I0303 07:46:27.077424 770 master.cpp:1469] Recovering from registrar
I0303 07:46:27.077818 770 registrar.cpp:307] Recovering registrar
I0303 07:46:27.109452 762 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 45.726225ms
I0303 07:46:27.109537 762 replica.cpp:320] Persisted replica status to STARTING
I0303 07:46:27.109920 763 recover.cpp:473] Replica is in STARTING status
I0303 07:46:27.111078 759 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (15011)@172.17.0.3:54257
I0303 07:46:27.111961 764 recover.cpp:193] Received a recover response from a replica in STARTING status
I0303 07:46:27.118065 764 recover.cpp:564] Updating replica status to VOTING
I0303 07:46:27.168000 762 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 49.389924ms
I0303 07:46:27.168092 762 replica.cpp:320] Persisted replica status to VOTING
I0303 07:46:27.168366 762 recover.cpp:578] Successfully joined the Paxos group
I0303 07:46:27.168576 762 recover.cpp:462] Recover process terminated
I0303 07:46:27.169327 762 log.cpp:659] Attempting to start the writer
I0303 07:46:27.171008 762 replica.cpp:493] Replica received implicit promise request from (15012)@172.17.0.3:54257 with proposal 1
I0303 07:46:27.251467 762 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 80.399424ms
I0303 07:46:27.251554 762 replica.cpp:342] Persisted promised to 1
I0303 07:46:27.252495 763 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0303 07:46:27.254469 763 replica.cpp:388] Replica received explicit promise request from (15013)@172.17.0.3:54257 for position 0 with proposal 2
I0303 07:46:27.307003 763 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 52.433895ms
I0303 07:46:27.307090 763 replica.cpp:712] Persisted action at 0
I0303 07:46:27.309676 763 replica.cpp:537] Replica received write request for position 0 from (15014)@172.17.0.3:54257
I0303 07:46:27.309854 763 leveldb.cpp:436] Reading position from leveldb took 76249ns
I0303 07:46:27.390465 763 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 80.509691ms
I0303 07:46:27.390552 763 replica.cpp:712] Persisted action at 0
I0303 07:46:27.394549 769 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0303 07:46:27.465482 769 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 70.844182ms
I0303 07:46:27.465574 769 replica.cpp:712] Persisted action at 0
I0303 07:46:27.465612 769 replica.cpp:697] Replica learned NOP action at position 0
I0303 07:46:27.466975 761 log.cpp:675] Writer started with ending position 0
I0303 07:46:27.468443 761 leveldb.cpp:436] Reading position from leveldb took 57765ns
I0303 07:46:27.469974 761 registrar.cpp:340] Successfully fetched the registry (0B) in 391.85408ms
I0303 07:46:27.470108 761 registrar.cpp:439] Applied 1 operations in 34601ns; attempting to update the 'registry'
I0303 07:46:27.471022 761 log.cpp:683] Attempting to append 170 bytes to the log
I0303 07:46:27.471155 756 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0303 07:46:27.472246 756 replica.cpp:537] Replica received write request for position 1 from (15015)@172.17.0.3:54257
I0303 07:46:27.498946 756 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 26.636533ms
I0303 07:46:27.499037 756 replica.cpp:712] Persisted action at 1
I0303 07:46:27.500481 756 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0303 07:46:27.524065 756 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 23.525657ms
I0303 07:46:27.524158 756 replica.cpp:712] Persisted action at 1
I0303 07:46:27.524194 756 replica.cpp:697] Replica learned APPEND action at position 1
I0303 07:46:27.526278 756 registrar.cpp:484] Successfully updated the 'registry' in 56.09984ms
I0303 07:46:27.526432 756 registrar.cpp:370] Successfully recovered registrar
I0303 07:46:27.526681 756 log.cpp:702] Attempting to truncate the log to 1
I0303 07:46:27.527161 756 master.cpp:1521] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0303 07:46:27.527390 770 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0303 07:46:27.527866 770 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0303 07:46:27.528982 766 replica.cpp:537] Replica received write request for position 2 from (15016)@172.17.0.3:54257
I0303 07:46:27.549178 766 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 20.122097ms
I0303 07:46:27.549280 766 replica.cpp:712] Persisted action at 2
I0303 07:46:27.550154 766 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0303 07:46:27.574327 766 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.118031ms
I0303 07:46:27.574493 766 leveldb.cpp:399] Deleting ~1 keys from leveldb took 75375ns
I0303 07:46:27.574522 766 replica.cpp:712] Persisted action at 2
I0303 07:46:27.574559 766 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0303 07:46:27.579474 736 scheduler.cpp:172] Version: 0.28.0
I0303 07:46:27.580442 763 scheduler.cpp:432] New master detected at master@172.17.0.3:54257
I0303 07:46:27.582197 760 scheduler.cpp:332] Connected with the master at http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:27.583495 755 scheduler.cpp:230] Sending SUBSCRIBE call to http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:27.584646 755 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 07:46:27.585207 755 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:50405
I0303 07:46:27.585448 755 master.cpp:1973] Received subscription request for HTTP framework 'default'
I0303 07:46:27.585515 755 master.cpp:1750] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0303 07:46:27.586231 755 master.cpp:2064] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0303 07:46:27.587290 767 master.hpp:1657] Sending heartbeat to 6fd214c8-bcc7-4762-b908-21b6c08b6bc9-0000
I0303 07:46:27.587735 755 hierarchical.cpp:265] Added framework 6fd214c8-bcc7-4762-b908-21b6c08b6bc9-0000
I0303 07:46:27.587823 755 hierarchical.cpp:1453] No resources available to allocate!
I0303 07:46:27.587862 755 hierarchical.cpp:1548] No inverse offers to send out!
I0303 07:46:27.587890 755 hierarchical.cpp:1130] Performed allocation for 0 slaves in 132448ns
I0303 07:46:27.588418 762 scheduler.cpp:602] Enqueuing event SUBSCRIBED received from http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:27.588915 762 scheduler.cpp:602] Enqueuing event HEARTBEAT received from http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:27.590019 765 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0303 07:46:27.590489 762 scheduler.cpp:230] Sending REQUEST call to http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:27.591581 766 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 07:46:27.592021 766 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:50406
I0303 07:46:27.592144 766 master.cpp:2670] Processing REQUEST call for framework 6fd214c8-bcc7-4762-b908-21b6c08b6bc9-0000 (default)
I0303 07:46:27.592320 760 hierarchical.cpp:589] Received resource request from framework 6fd214c8-bcc7-4762-b908-21b6c08b6bc9-0000
I0303 07:46:27.592742 736 master.cpp:1026] Master terminating
I0303 07:46:27.592993 766 hierarchical.cpp:326] Removed framework 6fd214c8-bcc7-4762-b908-21b6c08b6bc9-0000
E0303 07:46:27.593811 757 scheduler.cpp:575] End-Of-File received from master. The master closed the event stream
I0303 07:46:27.595706 757 scheduler.cpp:414] Re-detecting master
I0303 07:46:27.596019 757 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 07:46:27.596086 757 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 07:46:27.596834 757 scheduler.cpp:432] New master detected at master@172.17.0.3:54257
I0303 07:46:27.612818 760 scheduler.cpp:332] Connected with the master at http://172.17.0.3:54257/master/api/v1/scheduler
[ OK ] ContentType/SchedulerTest.Request/0 (816 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0303 07:46:27.715982 736 leveldb.cpp:174] Opened db in 83.341186ms
I0303 07:46:27.760998 736 leveldb.cpp:181] Compacted db in 44.928402ms
I0303 07:46:27.761090 736 leveldb.cpp:196] Created db iterator in 23149ns
I0303 07:46:27.761107 736 leveldb.cpp:202] Seeked to beginning of db in 2965ns
I0303 07:46:27.761117 736 leveldb.cpp:271] Iterated through 0 keys in the db in 220ns
I0303 07:46:27.761168 736 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0303 07:46:27.761812 763 recover.cpp:447] Starting replica recovery
I0303 07:46:27.762686 763 recover.cpp:473] Replica is in EMPTY status
I0303 07:46:27.765123 757 master.cpp:375] Master e595e34f-e0ee-47ea-9a78-960efec9c3aa (e766e26128b8) started on 172.17.0.3:54257
I0303 07:46:27.765156 757 master.cpp:377] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/I1YRuU/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="100secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/I1YRuU/master" --zk_session_timeout="10secs"
I0303 07:46:27.765542 757 master.cpp:424] Master allowing unauthenticated frameworks to register
I0303 07:46:27.765554 757 master.cpp:427] Master only allowing authenticated slaves to register
I0303 07:46:27.765563 757 credentials.hpp:35] Loading credentials for authentication from '/tmp/I1YRuU/credentials'
I0303 07:46:27.765945 757 master.cpp:467] Using default 'crammd5' authenticator
I0303 07:46:27.766103 757 master.cpp:536] Using default 'basic' HTTP authenticator
I0303 07:46:27.766261 757 master.cpp:570] Authorization enabled
I0303 07:46:27.766450 768 hierarchical.cpp:144] Initialized hierarchical allocator process
I0303 07:46:27.766472 758 whitelist_watcher.cpp:77] No whitelist given
I0303 07:46:27.768074 759 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (15025)@172.17.0.3:54257
I0303 07:46:27.768370 758 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0303 07:46:27.769515 759 recover.cpp:564] Updating replica status to STARTING
I0303 07:46:27.769920 769 master.cpp:1711] The newly elected leader is master@172.17.0.3:54257 with id e595e34f-e0ee-47ea-9a78-960efec9c3aa
I0303 07:46:27.769955 769 master.cpp:1724] Elected as the leading master!
I0303 07:46:27.769979 769 master.cpp:1469] Recovering from registrar
I0303 07:46:27.770160 768 registrar.cpp:307] Recovering registrar
I0303 07:46:27.811064 756 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 40.324546ms
I0303 07:46:27.811157 756 replica.cpp:320] Persisted replica status to STARTING
I0303 07:46:27.811555 756 recover.cpp:473] Replica is in STARTING status
I0303 07:46:27.813606 756 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (15026)@172.17.0.3:54257
I0303 07:46:27.814059 756 recover.cpp:193] Received a recover response from a replica in STARTING status
I0303 07:46:27.814872 756 recover.cpp:564] Updating replica status to VOTING
I0303 07:46:27.861186 756 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 46.033107ms
I0303 07:46:27.861284 756 replica.cpp:320] Persisted replica status to VOTING
I0303 07:46:27.861527 761 recover.cpp:578] Successfully joined the Paxos group
I0303 07:46:27.861816 766 recover.cpp:462] Recover process terminated
I0303 07:46:27.866699 761 log.cpp:659] Attempting to start the writer
I0303 07:46:27.868250 764 replica.cpp:493] Replica received implicit promise request from (15027)@172.17.0.3:54257 with proposal 1
I0303 07:46:27.908170 764 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.854935ms
I0303 07:46:27.908270 764 replica.cpp:342] Persisted promised to 1
I0303 07:46:27.909167 764 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0303 07:46:27.910426 764 replica.cpp:388] Replica received explicit promise request from (15028)@172.17.0.3:54257 for position 0 with proposal 2
I0303 07:46:27.953073 764 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 42.577028ms
I0303 07:46:27.953166 764 replica.cpp:712] Persisted action at 0
I0303 07:46:27.954988 764 replica.cpp:537] Replica received write request for position 0 from (15029)@172.17.0.3:54257
I0303 07:46:27.955062 764 leveldb.cpp:436] Reading position from leveldb took 38752ns
I0303 07:46:27.994864 764 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 39.738043ms
I0303 07:46:27.994962 764 replica.cpp:712] Persisted action at 0
I0303 07:46:27.996114 764 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0303 07:46:28.050781 764 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 54.607529ms
I0303 07:46:28.050874 764 replica.cpp:712] Persisted action at 0
I0303 07:46:28.050911 764 replica.cpp:697] Replica learned NOP action at position 0
I0303 07:46:28.052177 766 log.cpp:675] Writer started with ending position 0
I0303 07:46:28.053673 766 leveldb.cpp:436] Reading position from leveldb took 59908ns
I0303 07:46:28.054991 767 registrar.cpp:340] Successfully fetched the registry (0B) in 284.783872ms
I0303 07:46:28.055136 767 registrar.cpp:439] Applied 1 operations in 36070ns; attempting to update the 'registry'
I0303 07:46:28.055888 767 log.cpp:683] Attempting to append 170 bytes to the log
I0303 07:46:28.056033 761 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0303 07:46:28.056892 761 replica.cpp:537] Replica received write request for position 1 from (15030)@172.17.0.3:54257
I0303 07:46:28.100971 761 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 44.024824ms
I0303 07:46:28.101052 761 replica.cpp:712] Persisted action at 1
I0303 07:46:28.102404 761 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0303 07:46:28.125967 761 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 23.504569ms
I0303 07:46:28.126060 761 replica.cpp:712] Persisted action at 1
I0303 07:46:28.126096 761 replica.cpp:697] Replica learned APPEND action at position 1
I0303 07:46:28.128149 761 registrar.cpp:484] Successfully updated the 'registry' in 72.944896ms
I0303 07:46:28.128311 761 registrar.cpp:370] Successfully recovered registrar
I0303 07:46:28.128559 761 log.cpp:702] Attempting to truncate the log to 1
I0303 07:46:28.129017 761 master.cpp:1521] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0303 07:46:28.129107 761 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0303 07:46:28.129534 757 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0303 07:46:28.131428 761 replica.cpp:537] Replica received write request for position 2 from (15031)@172.17.0.3:54257
I0303 07:46:28.151368 761 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 19.856809ms
I0303 07:46:28.151464 761 replica.cpp:712] Persisted action at 2
I0303 07:46:28.153205 761 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0303 07:46:28.176636 761 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 23.357042ms
I0303 07:46:28.176803 761 leveldb.cpp:399] Deleting ~1 keys from leveldb took 75960ns
I0303 07:46:28.176833 761 replica.cpp:712] Persisted action at 2
I0303 07:46:28.176873 761 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0303 07:46:28.184624 736 scheduler.cpp:172] Version: 0.28.0
I0303 07:46:28.185606 768 scheduler.cpp:432] New master detected at master@172.17.0.3:54257
I0303 07:46:28.187809 757 scheduler.cpp:332] Connected with the master at http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:28.189692 767 scheduler.cpp:230] Sending SUBSCRIBE call to http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:28.191330 767 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 07:46:28.191967 767 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:50421
I0303 07:46:28.192445 767 master.cpp:1973] Received subscription request for HTTP framework 'default'
I0303 07:46:28.192524 767 master.cpp:1750] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0303 07:46:28.193358 767 master.cpp:2064] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0303 07:46:28.194545 759 hierarchical.cpp:265] Added framework e595e34f-e0ee-47ea-9a78-960efec9c3aa-0000
I0303 07:46:28.194705 759 hierarchical.cpp:1453] No resources available to allocate!
I0303 07:46:28.194852 759 hierarchical.cpp:1548] No inverse offers to send out!
I0303 07:46:28.194958 759 hierarchical.cpp:1130] Performed allocation for 0 slaves in 330516ns
I0303 07:46:28.195320 759 master.hpp:1657] Sending heartbeat to e595e34f-e0ee-47ea-9a78-960efec9c3aa-0000
I0303 07:46:28.196990 757 scheduler.cpp:602] Enqueuing event SUBSCRIBED received from http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:28.198981 767 scheduler.cpp:230] Sending REQUEST call to http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:28.199602 767 scheduler.cpp:602] Enqueuing event HEARTBEAT received from http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:28.201007 767 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0303 07:46:28.201305 757 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 07:46:28.202173 757 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:50423
I0303 07:46:28.202622 757 master.cpp:2670] Processing REQUEST call for framework e595e34f-e0ee-47ea-9a78-960efec9c3aa-0000 (default)
I0303 07:46:28.203480 769 hierarchical.cpp:589] Received resource request from framework e595e34f-e0ee-47ea-9a78-960efec9c3aa-0000
I0303 07:46:28.204419 759 master.cpp:1026] Master terminating
I0303 07:46:28.205340 759 hierarchical.cpp:326] Removed framework e595e34f-e0ee-47ea-9a78-960efec9c3aa-0000
E0303 07:46:28.206203 755 scheduler.cpp:575] End-Of-File received from master. The master closed the event stream
I0303 07:46:28.207478 755 scheduler.cpp:414] Re-detecting master
I0303 07:46:28.207808 755 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 07:46:28.207861 755 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 07:46:28.207964 755 scheduler.cpp:432] New master detected at master@172.17.0.3:54257
I0303 07:46:28.213348 770 scheduler.cpp:332] Connected with the master at http://172.17.0.3:54257/master/api/v1/scheduler
[ OK ] ContentType/SchedulerTest.Request/1 (587 ms)
[----------] 26 tests from ContentType/SchedulerTest (23509 ms total)
[----------] Global test environment tear-down
E0303 07:46:28.339565 736 environment.cpp:752] Failed to remove '/tmp/LogZooKeeperTest_WriteRead_uXnJpt': No such file or directory
E0303 07:46:28.339653 736 environment.cpp:752] Failed to remove '/tmp/LogZooKeeperTest_LostZooKeeper_UNDfRk': No such file or directory
[==========] 997 tests from 128 test cases ran. (859935 ms total)
[ PASSED ] 996 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] AppcImageFetcherTest.SimpleFetch
1 FAILED TEST
YOU HAVE 6 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[3]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[3]: *** [check-am] Error 2
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.28.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1456987289-14902
Untagged: mesos-1456987289-14902:latest
Deleted: 0913efe34aa56f8ace67a4529845b8a29d15a290194598f2e5f36632a6c716ad
Deleted: 60c28883ea2f75a626f3d083383887b8f4be0df089a64576556ae26e3a2eb0eb
Deleted: 4e20efeffbb1e86b0b2cfb938094d00eaa2d531726f6fee32d4785591a5a2874
Deleted: f43585fc27f8781dcbba81a7b0e09166f91fa2aa3c30fdeb96acf106ae50b3ea
Deleted: c5d6815738515bd1fc99bce6493e4051fcf022aa45b267515c75de4fc8b58dc4
Deleted: 8d1dff9d23c8799d8eafc554afb48b9c0b003067379906e9ba7ff2ceec364fbc
Deleted: 7d19f999fb8d7f820e0e7ad027d85143a22019cd1da2b8f0b1898e3787905b42
Deleted: fb83b8ec33dade061831b49f5cd84f7a47afe6d415ffbda39f5c4b4f9dd03368
Deleted: 81915dace72c9dde2de55cd3adad49a47d9fdec212597832960ab0ed5a5f43cc
Deleted: 5bc12fcc62a0e2e98d71ba636579e543e69af4d8d1d648a3895359ff30b419bf
Deleted: 6d8711bbe973afe5ca6116742b16132113630d6ecc2cc62a161aef906b532c5f
Deleted: 23e6fecc0ec35f15537ed2a5ac097cbb6a479da4a2c6dbc499492e3bb9b3dd77
Deleted: fdc7e40a37428e2846212b5e16ac71816be601583a7bc8d3146c5222ff70dfb0
Deleted: b8c1e20f02a37de805be0ec81efc83d0d9d48ce87b0cc123c8b907fa188f9677
Deleted: 1b1ab1a60a175c7c3b98b1f047f1bebe5c0bf92deb146ff9c4930c7865741a2c
Deleted: b345f26fe143c59599b716787042f918555ad7e5dd6c6e0cafb261faf72f5fd9
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: Mesos » gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(docker||Hadoop)&&(!ubuntu-us1) #1764
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)/1764/changes>
Changes:
[bmahler] Updated /metrics/snapshot rate limiting to be configurable.
[bmahler] Documented LIBPROCESS_METRICS_SNAPSHOT_ENDPOINT_RATE_LIMIT.
[bmahler] Disabled rate limiting of /metrics/snapshot in the mesos tests.
[bmahler] Updated tests now that /metrics/snapshot is not rate limited.
------------------------------------------
[...truncated 166488 lines...]
I0303 06:03:26.328289 770 master.cpp:424] Master allowing unauthenticated frameworks to register
I0303 06:03:26.328299 770 master.cpp:427] Master only allowing authenticated slaves to register
I0303 06:03:26.328305 770 credentials.hpp:35] Loading credentials for authentication from '/tmp/Fj4rVM/credentials'
I0303 06:03:26.328543 767 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0303 06:03:26.328591 770 master.cpp:467] Using default 'crammd5' authenticator
I0303 06:03:26.328769 770 master.cpp:536] Using default 'basic' HTTP authenticator
I0303 06:03:26.329032 770 master.cpp:570] Authorization enabled
I0303 06:03:26.329109 761 recover.cpp:564] Updating replica status to STARTING
I0303 06:03:26.329426 757 hierarchical.cpp:144] Initialized hierarchical allocator process
I0303 06:03:26.329455 761 whitelist_watcher.cpp:77] No whitelist given
I0303 06:03:26.329906 763 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 529886ns
I0303 06:03:26.329931 763 replica.cpp:320] Persisted replica status to STARTING
I0303 06:03:26.330229 765 recover.cpp:473] Replica is in STARTING status
I0303 06:03:26.331281 757 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (15010)@172.17.0.2:58861
I0303 06:03:26.331785 758 master.cpp:1711] The newly elected leader is master@172.17.0.2:58861 with id acecccda-5bca-48d2-9823-e0cca2c13fa4
I0303 06:03:26.331899 758 master.cpp:1724] Elected as the leading master!
I0303 06:03:26.332051 758 master.cpp:1469] Recovering from registrar
I0303 06:03:26.332124 771 recover.cpp:193] Received a recover response from a replica in STARTING status
I0303 06:03:26.332571 758 registrar.cpp:307] Recovering registrar
I0303 06:03:26.333076 766 recover.cpp:564] Updating replica status to VOTING
I0303 06:03:26.333663 759 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 402142ns
I0303 06:03:26.333696 759 replica.cpp:320] Persisted replica status to VOTING
I0303 06:03:26.333830 769 recover.cpp:578] Successfully joined the Paxos group
I0303 06:03:26.334105 769 recover.cpp:462] Recover process terminated
I0303 06:03:26.334631 767 log.cpp:659] Attempting to start the writer
I0303 06:03:26.336374 768 replica.cpp:493] Replica received implicit promise request from (15011)@172.17.0.2:58861 with proposal 1
I0303 06:03:26.336736 768 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 322516ns
I0303 06:03:26.336767 768 replica.cpp:342] Persisted promised to 1
I0303 06:03:26.337581 767 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0303 06:03:26.339073 766 replica.cpp:388] Replica received explicit promise request from (15012)@172.17.0.2:58861 for position 0 with proposal 2
I0303 06:03:26.339481 766 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 353993ns
I0303 06:03:26.339511 766 replica.cpp:712] Persisted action at 0
I0303 06:03:26.340832 757 replica.cpp:537] Replica received write request for position 0 from (15013)@172.17.0.2:58861
I0303 06:03:26.340903 757 leveldb.cpp:436] Reading position from leveldb took 32152ns
I0303 06:03:26.341310 757 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 333925ns
I0303 06:03:26.341341 757 replica.cpp:712] Persisted action at 0
I0303 06:03:26.342113 759 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0303 06:03:26.342633 759 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 365563ns
I0303 06:03:26.342664 759 replica.cpp:712] Persisted action at 0
I0303 06:03:26.342692 759 replica.cpp:697] Replica learned NOP action at position 0
I0303 06:03:26.343372 759 log.cpp:675] Writer started with ending position 0
I0303 06:03:26.344642 769 leveldb.cpp:436] Reading position from leveldb took 33734ns
I0303 06:03:26.345823 765 registrar.cpp:340] Successfully fetched the registry (0B) in 13.121024ms
I0303 06:03:26.346004 765 registrar.cpp:439] Applied 1 operations in 71808ns; attempting to update the 'registry'
I0303 06:03:26.346843 761 log.cpp:683] Attempting to append 170 bytes to the log
I0303 06:03:26.347028 762 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0303 06:03:26.347988 761 replica.cpp:537] Replica received write request for position 1 from (15014)@172.17.0.2:58861
I0303 06:03:26.348402 761 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 361130ns
I0303 06:03:26.348433 761 replica.cpp:712] Persisted action at 1
I0303 06:03:26.349159 766 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0303 06:03:26.349535 766 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 334348ns
I0303 06:03:26.349565 766 replica.cpp:712] Persisted action at 1
I0303 06:03:26.349588 766 replica.cpp:697] Replica learned APPEND action at position 1
I0303 06:03:26.350814 763 registrar.cpp:484] Successfully updated the 'registry' in 4.740096ms
I0303 06:03:26.350996 763 registrar.cpp:370] Successfully recovered registrar
I0303 06:03:26.351032 757 log.cpp:702] Attempting to truncate the log to 1
I0303 06:03:26.351212 768 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0303 06:03:26.351557 757 master.cpp:1521] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0303 06:03:26.351585 764 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0303 06:03:26.352318 756 replica.cpp:537] Replica received write request for position 2 from (15015)@172.17.0.2:58861
I0303 06:03:26.352686 756 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 320681ns
I0303 06:03:26.352717 756 replica.cpp:712] Persisted action at 2
I0303 06:03:26.353864 757 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0303 06:03:26.354399 757 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 480120ns
I0303 06:03:26.354452 757 leveldb.cpp:399] Deleting ~1 keys from leveldb took 30076ns
I0303 06:03:26.354470 757 replica.cpp:712] Persisted action at 2
I0303 06:03:26.354499 757 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0303 06:03:26.362509 737 scheduler.cpp:172] Version: 0.28.0
I0303 06:03:26.363203 763 scheduler.cpp:432] New master detected at master@172.17.0.2:58861
I0303 06:03:26.364797 762 scheduler.cpp:332] Connected with the master at http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.366225 763 scheduler.cpp:230] Sending SUBSCRIBE call to http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.367178 757 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 06:03:26.367730 771 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:35285
I0303 06:03:26.368006 771 master.cpp:1973] Received subscription request for HTTP framework 'default'
I0303 06:03:26.368077 771 master.cpp:1750] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0303 06:03:26.368391 771 master.cpp:2064] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0303 06:03:26.368821 767 hierarchical.cpp:265] Added framework acecccda-5bca-48d2-9823-e0cca2c13fa4-0000
I0303 06:03:26.368909 767 hierarchical.cpp:1453] No resources available to allocate!
I0303 06:03:26.368965 767 hierarchical.cpp:1548] No inverse offers to send out!
I0303 06:03:26.368978 758 master.hpp:1657] Sending heartbeat to acecccda-5bca-48d2-9823-e0cca2c13fa4-0000
I0303 06:03:26.368993 767 hierarchical.cpp:1130] Performed allocation for 0 slaves in 143850ns
I0303 06:03:26.370343 761 scheduler.cpp:602] Enqueuing event SUBSCRIBED received from http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.370832 761 scheduler.cpp:602] Enqueuing event HEARTBEAT received from http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.371737 757 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0303 06:03:26.371727 761 scheduler.cpp:230] Sending REQUEST call to http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.372835 763 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 06:03:26.373313 756 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:35286
I0303 06:03:26.373437 756 master.cpp:2670] Processing REQUEST call for framework acecccda-5bca-48d2-9823-e0cca2c13fa4-0000 (default)
I0303 06:03:26.373595 762 hierarchical.cpp:589] Received resource request from framework acecccda-5bca-48d2-9823-e0cca2c13fa4-0000
I0303 06:03:26.374181 760 master.cpp:1026] Master terminating
I0303 06:03:26.374408 762 hierarchical.cpp:326] Removed framework acecccda-5bca-48d2-9823-e0cca2c13fa4-0000
E0303 06:03:26.375155 756 scheduler.cpp:575] End-Of-File received from master. The master closed the event stream
I0303 06:03:26.376646 760 scheduler.cpp:414] Re-detecting master
I0303 06:03:26.377310 760 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 06:03:26.377372 760 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 06:03:26.377570 760 scheduler.cpp:432] New master detected at master@172.17.0.2:58861
I0303 06:03:26.379185 757 scheduler.cpp:332] Connected with the master at http://172.17.0.2:58861/master/api/v1/scheduler
[ OK ] ContentType/SchedulerTest.Request/0 (64 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0303 06:03:26.388181 737 leveldb.cpp:174] Opened db in 2.732482ms
I0303 06:03:26.389035 737 leveldb.cpp:181] Compacted db in 813558ns
I0303 06:03:26.389093 737 leveldb.cpp:196] Created db iterator in 20742ns
I0303 06:03:26.389116 737 leveldb.cpp:202] Seeked to beginning of db in 2140ns
I0303 06:03:26.389127 737 leveldb.cpp:271] Iterated through 0 keys in the db in 305ns
I0303 06:03:26.389166 737 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0303 06:03:26.390018 767 recover.cpp:447] Starting replica recovery
I0303 06:03:26.390275 767 recover.cpp:473] Replica is in EMPTY status
I0303 06:03:26.391562 760 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (15023)@172.17.0.2:58861
I0303 06:03:26.392118 757 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0303 06:03:26.392572 756 recover.cpp:564] Updating replica status to STARTING
I0303 06:03:26.393383 770 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 487007ns
I0303 06:03:26.393420 770 replica.cpp:320] Persisted replica status to STARTING
I0303 06:03:26.393721 762 recover.cpp:473] Replica is in STARTING status
I0303 06:03:26.393746 766 master.cpp:375] Master 5068a93f-0e7d-4584-81ec-a14d21fa8370 (d35e5f56a77e) started on 172.17.0.2:58861
I0303 06:03:26.393774 766 master.cpp:377] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/mACY1p/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="100secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/mACY1p/master" --zk_session_timeout="10secs"
I0303 06:03:26.394181 766 master.cpp:424] Master allowing unauthenticated frameworks to register
I0303 06:03:26.394198 766 master.cpp:427] Master only allowing authenticated slaves to register
I0303 06:03:26.394213 766 credentials.hpp:35] Loading credentials for authentication from '/tmp/mACY1p/credentials'
I0303 06:03:26.394596 766 master.cpp:467] Using default 'crammd5' authenticator
I0303 06:03:26.394774 766 master.cpp:536] Using default 'basic' HTTP authenticator
I0303 06:03:26.394901 771 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (15024)@172.17.0.2:58861
I0303 06:03:26.394985 766 master.cpp:570] Authorization enabled
I0303 06:03:26.395193 764 hierarchical.cpp:144] Initialized hierarchical allocator process
I0303 06:03:26.395195 762 whitelist_watcher.cpp:77] No whitelist given
I0303 06:03:26.395424 763 recover.cpp:193] Received a recover response from a replica in STARTING status
I0303 06:03:26.395882 769 recover.cpp:564] Updating replica status to VOTING
I0303 06:03:26.396491 756 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 338295ns
I0303 06:03:26.396519 756 replica.cpp:320] Persisted replica status to VOTING
I0303 06:03:26.396669 768 recover.cpp:578] Successfully joined the Paxos group
I0303 06:03:26.396935 768 recover.cpp:462] Recover process terminated
I0303 06:03:26.397766 758 master.cpp:1711] The newly elected leader is master@172.17.0.2:58861 with id 5068a93f-0e7d-4584-81ec-a14d21fa8370
I0303 06:03:26.397799 758 master.cpp:1724] Elected as the leading master!
I0303 06:03:26.397814 758 master.cpp:1469] Recovering from registrar
I0303 06:03:26.397982 765 registrar.cpp:307] Recovering registrar
I0303 06:03:26.398502 763 log.cpp:659] Attempting to start the writer
I0303 06:03:26.399648 757 replica.cpp:493] Replica received implicit promise request from (15026)@172.17.0.2:58861 with proposal 1
I0303 06:03:26.400009 757 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 327521ns
I0303 06:03:26.400035 757 replica.cpp:342] Persisted promised to 1
I0303 06:03:26.400660 769 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0303 06:03:26.401792 763 replica.cpp:388] Replica received explicit promise request from (15027)@172.17.0.2:58861 for position 0 with proposal 2
I0303 06:03:26.402127 763 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 290781ns
I0303 06:03:26.402154 763 replica.cpp:712] Persisted action at 0
I0303 06:03:26.403151 769 replica.cpp:537] Replica received write request for position 0 from (15028)@172.17.0.2:58861
I0303 06:03:26.403221 769 leveldb.cpp:436] Reading position from leveldb took 33268ns
I0303 06:03:26.403548 769 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 273838ns
I0303 06:03:26.403573 769 replica.cpp:712] Persisted action at 0
I0303 06:03:26.404157 759 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0303 06:03:26.404525 759 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 334962ns
I0303 06:03:26.404554 759 replica.cpp:712] Persisted action at 0
I0303 06:03:26.404582 759 replica.cpp:697] Replica learned NOP action at position 0
I0303 06:03:26.405216 765 log.cpp:675] Writer started with ending position 0
I0303 06:03:26.406675 759 leveldb.cpp:436] Reading position from leveldb took 34634ns
I0303 06:03:26.407979 762 registrar.cpp:340] Successfully fetched the registry (0B) in 9.924096ms
I0303 06:03:26.408107 762 registrar.cpp:439] Applied 1 operations in 32472ns; attempting to update the 'registry'
I0303 06:03:26.409001 770 log.cpp:683] Attempting to append 170 bytes to the log
I0303 06:03:26.409153 759 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0303 06:03:26.409988 765 replica.cpp:537] Replica received write request for position 1 from (15029)@172.17.0.2:58861
I0303 06:03:26.410452 765 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 348301ns
I0303 06:03:26.410485 765 replica.cpp:712] Persisted action at 1
I0303 06:03:26.411231 770 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0303 06:03:26.411633 770 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 360443ns
I0303 06:03:26.411664 770 replica.cpp:712] Persisted action at 1
I0303 06:03:26.411694 770 replica.cpp:697] Replica learned APPEND action at position 1
I0303 06:03:26.412816 767 registrar.cpp:484] Successfully updated the 'registry' in 4.636928ms
I0303 06:03:26.412997 767 registrar.cpp:370] Successfully recovered registrar
I0303 06:03:26.413162 768 log.cpp:702] Attempting to truncate the log to 1
I0303 06:03:26.413332 760 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0303 06:03:26.413916 759 master.cpp:1521] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0303 06:03:26.414250 762 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0303 06:03:26.414451 764 replica.cpp:537] Replica received write request for position 2 from (15030)@172.17.0.2:58861
I0303 06:03:26.414819 764 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 320799ns
I0303 06:03:26.414850 764 replica.cpp:712] Persisted action at 2
I0303 06:03:26.415727 761 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0303 06:03:26.416085 761 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 314908ns
I0303 06:03:26.416158 761 leveldb.cpp:399] Deleting ~1 keys from leveldb took 40489ns
I0303 06:03:26.416187 761 replica.cpp:712] Persisted action at 2
I0303 06:03:26.416209 761 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0303 06:03:26.424468 737 scheduler.cpp:172] Version: 0.28.0
I0303 06:03:26.425623 769 scheduler.cpp:432] New master detected at master@172.17.0.2:58861
I0303 06:03:26.427839 769 scheduler.cpp:332] Connected with the master at http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.429163 769 scheduler.cpp:230] Sending SUBSCRIBE call to http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.430287 764 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 06:03:26.430752 763 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:35289
I0303 06:03:26.431074 763 master.cpp:1973] Received subscription request for HTTP framework 'default'
I0303 06:03:26.431128 763 master.cpp:1750] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0303 06:03:26.431365 763 master.cpp:2064] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0303 06:03:26.431682 764 hierarchical.cpp:265] Added framework 5068a93f-0e7d-4584-81ec-a14d21fa8370-0000
I0303 06:03:26.431753 764 hierarchical.cpp:1453] No resources available to allocate!
I0303 06:03:26.431776 756 master.hpp:1657] Sending heartbeat to 5068a93f-0e7d-4584-81ec-a14d21fa8370-0000
I0303 06:03:26.431789 764 hierarchical.cpp:1548] No inverse offers to send out!
I0303 06:03:26.431813 764 hierarchical.cpp:1130] Performed allocation for 0 slaves in 108141ns
I0303 06:03:26.432418 764 scheduler.cpp:602] Enqueuing event SUBSCRIBED received from http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.432832 764 scheduler.cpp:602] Enqueuing event HEARTBEAT received from http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.433595 760 scheduler.cpp:230] Sending REQUEST call to http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.433626 768 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0303 06:03:26.435045 760 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 06:03:26.435531 756 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:35290
I0303 06:03:26.435864 756 master.cpp:2670] Processing REQUEST call for framework 5068a93f-0e7d-4584-81ec-a14d21fa8370-0000 (default)
I0303 06:03:26.436075 761 hierarchical.cpp:589] Received resource request from framework 5068a93f-0e7d-4584-81ec-a14d21fa8370-0000
I0303 06:03:26.437233 761 master.cpp:1026] Master terminating
I0303 06:03:26.437463 756 hierarchical.cpp:326] Removed framework 5068a93f-0e7d-4584-81ec-a14d21fa8370-0000
E0303 06:03:26.438262 771 scheduler.cpp:575] End-Of-File received from master. The master closed the event stream
I0303 06:03:26.439854 771 scheduler.cpp:414] Re-detecting master
I0303 06:03:26.440524 771 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 06:03:26.440681 771 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 06:03:26.440783 771 scheduler.cpp:432] New master detected at master@172.17.0.2:58861
I0303 06:03:26.442837 758 scheduler.cpp:332] Connected with the master at http://172.17.0.2:58861/master/api/v1/scheduler
[ OK ] ContentType/SchedulerTest.Request/1 (63 ms)
[----------] 26 tests from ContentType/SchedulerTest (4661 ms total)
[----------] Global test environment tear-down
E0303 06:03:26.559387 737 environment.cpp:752] Failed to remove '/tmp/LogZooKeeperTest_WriteRead_ttsyl7': No such file or directory
E0303 06:03:26.559449 737 environment.cpp:752] Failed to remove '/tmp/LogZooKeeperTest_LostZooKeeper_etsrgN': No such file or directory
[==========] 997 tests from 128 test cases ran. (326824 ms total)
[ PASSED ] 996 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] AppcImageFetcherTest.SimpleFetch
1 FAILED TEST
YOU HAVE 6 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.28.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1456983087-5826
Untagged: mesos-1456983087-5826:latest
Deleted: 3917f89dcb5bc05ec40808db4fa478ce78551d483d4d88fb97eb1fe091b1b0f2
Deleted: 5d7f90357283de3251f8b81399c5355f9df4dd1f26a3b25fab63c4775d3e7995
Deleted: efbbdec049d2f2a69dfcd1813e22490242c9bb59e8e381fa3b5f8e21ca0982f0
Deleted: f402027eb52684b7507490faebef0d70118afe90a19c5c68a532004c36b9db09
Deleted: f0c95fec1c2c2e02771c60c68013dbed7400c9f64fa3b42b640aeeb5d741777e
Deleted: be870f0f19b59d3dd1e3e60b1157c6a3fb40b027cc631f2b5dc52267105814a3
Deleted: 3433893649e26ccb30e8191c40655dd541221acb52e0c05642839a6b3bb342ee
Deleted: fdcd90c7f09a452587c9b63f2e7d828ccd9a1f108a8394e4439261ecb3576c36
Deleted: 9f9667b087b2d6abd4ffeb9cb80e8a85003f8bd141a9c584660ecb2e71f9a424
Deleted: 1c8f7e83f0d77e860629284aabb0049d266d283943ebbbfd283f6fc9a442950d
Deleted: e1bfa794d1ee58184d42a42104ddfee737dd90fdc251c2f77f13aca642eb5983
Deleted: 060db92ac8da736b5050efa17c294e2b3a853694233cdeba8433f16f89801a79
Deleted: c6a4d016e14391592b0263a7625b9e1f61e7b82ab9809100f35f5093bc88ded3
Deleted: a66a00daf3a57e2577b7d9d3de471caf10e3fb37069b1ca0ac7d9ee1a37bba81
Deleted: b6c3a0e9d3a060baf8cde447933bc0ca12d47a486cef52c9bb81001e95e89751
Deleted: 2f836507404116b8af399d6c7a40f404927158112042f3f008085d26b8ea81a8
Build step 'Execute shell' marked build as failure