You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2014/06/20 02:07:46 UTC
Build failed in Jenkins: Mesos-Ubuntu-distcheck #161
See <https://builds.apache.org/job/Mesos-Ubuntu-distcheck/161/changes>
Changes:
[yujie.jay] Fixed a compiler error due to ambiguous UNREACHABLE in Subprocess.
------------------------------------------
[...truncated 57958 lines...]
I0620 00:07:38.837755 32127 master.cpp:286] Master 20140620-000738-1032504131-60427-32101 (juno.apache.org) started on 67.195.138.61:60427
I0620 00:07:38.837887 32127 master.cpp:323] Master only allowing authenticated frameworks to register
I0620 00:07:38.837977 32127 master.cpp:328] Master only allowing authenticated slaves to register
I0620 00:07:38.838050 32127 credentials.hpp:35] Loading credentials for authentication from '/tmp/AllocatorZooKeeperTest_0_FrameworkReregistersFirst_yZYbW6/credentials'
I0620 00:07:38.838177 32127 master.cpp:354] Authorization enabled
I0620 00:07:38.838546 32123 master.cpp:120] No whitelist given. Advertising offers for all slaves
2014-06-20 00:07:38,837:32101(0x2b3ef135c700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:59486]
I0620 00:07:38.838887 32129 hierarchical_allocator_process.hpp:301] Initializing hierarchical allocator process with master : master@67.195.138.61:60427
I0620 00:07:38.839035 32127 contender.cpp:131] Joining the ZK group
2014-06-20 00:07:38,849:32101(0x2b3ef1136700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:59486], sessionId=0x146b699804c0010, negotiated timeout=10000
I0620 00:07:38.849254 32127 group.cpp:313] Group process (group(76)@67.195.138.61:60427) connected to ZooKeeper
I0620 00:07:38.849277 32127 group.cpp:787] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0)
I0620 00:07:38.849285 32127 group.cpp:385] Trying to create path '/znode' in ZooKeeper
2014-06-20 00:07:38,857:32101(0x2b3ef2989700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:59486], sessionId=0x146b699804c0011, negotiated timeout=10000
I0620 00:07:38.857561 32126 group.cpp:313] Group process (group(74)@67.195.138.61:60427) connected to ZooKeeper
I0620 00:07:38.857576 32126 group.cpp:787] Syncing group operations: queue size (joins, cancels, datas) = (1, 0, 0)
I0620 00:07:38.857584 32126 group.cpp:385] Trying to create path '/znode/log_replicas' in ZooKeeper
2014-06-20 00:07:38,857:32101(0x2b3ef0f35700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:59486], sessionId=0x146b699804c0012, negotiated timeout=10000
I0620 00:07:38.858041 32123 group.cpp:313] Group process (group(73)@67.195.138.61:60427) connected to ZooKeeper
I0620 00:07:38.858062 32123 group.cpp:787] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0)
I0620 00:07:38.858072 32123 group.cpp:385] Trying to create path '/znode/log_replicas' in ZooKeeper
2014-06-20 00:07:38,858:32101(0x2b3ef135c700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:59486], sessionId=0x146b699804c0013, negotiated timeout=10000
I0620 00:07:38.859032 32129 group.cpp:313] Group process (group(75)@67.195.138.61:60427) connected to ZooKeeper
I0620 00:07:38.859050 32129 group.cpp:787] Syncing group operations: queue size (joins, cancels, datas) = (1, 0, 0)
I0620 00:07:38.859057 32129 group.cpp:385] Trying to create path '/znode' in ZooKeeper
I0620 00:07:38.860069 32127 group.cpp:714] Found non-sequence node 'log_replicas' at '/znode' in ZooKeeper
I0620 00:07:38.865718 32125 network.hpp:423] ZooKeeper group memberships changed
I0620 00:07:38.865809 32124 group.cpp:658] Trying to get '/znode/log_replicas/0000000003' in ZooKeeper
I0620 00:07:38.874152 32128 contender.cpp:247] New candidate (id='4') has entered the contest for leadership
I0620 00:07:38.874744 32124 network.hpp:461] ZooKeeper group PIDs: { log-replica(391)@67.195.138.61:60427 }
I0620 00:07:38.874794 32130 group.cpp:714] Found non-sequence node 'log_replicas' at '/znode' in ZooKeeper
I0620 00:07:38.874997 32123 group.cpp:714] Found non-sequence node 'log_replicas' at '/znode' in ZooKeeper
I0620 00:07:38.875072 32123 detector.cpp:138] Detected a new leader: (id='4')
I0620 00:07:38.875231 32128 group.cpp:658] Trying to get '/znode/info_0000000004' in ZooKeeper
I0620 00:07:38.875259 32126 detector.cpp:138] Detected a new leader: (id='4')
I0620 00:07:38.875489 32129 group.cpp:714] Found non-sequence node 'log_replicas' at '/znode' in ZooKeeper
I0620 00:07:38.875622 32127 group.cpp:714] Found non-sequence node 'log_replicas' at '/znode' in ZooKeeper
I0620 00:07:38.875695 32130 group.cpp:658] Trying to get '/znode/info_0000000004' in ZooKeeper
I0620 00:07:38.875741 32123 detector.cpp:138] Detected a new leader: (id='4')
I0620 00:07:38.875932 32127 group.cpp:658] Trying to get '/znode/info_0000000004' in ZooKeeper
I0620 00:07:38.876246 32128 detector.cpp:382] A new leading master (UPID=master@67.195.138.61:60427) is detected
I0620 00:07:38.876330 32128 sched.cpp:235] New master detected at master@67.195.138.61:60427
I0620 00:07:38.876410 32128 sched.cpp:285] Authenticating with master master@67.195.138.61:60427
I0620 00:07:38.876497 32126 authenticatee.hpp:128] Creating new client SASL connection
I0620 00:07:38.876495 32123 detector.cpp:382] A new leading master (UPID=master@67.195.138.61:60427) is detected
I0620 00:07:38.876562 32129 master.cpp:1077] The newly elected leader is master@67.195.138.61:60427 with id 20140620-000738-1032504131-60427-32101
I0620 00:07:38.876579 32129 master.cpp:1090] Elected as the leading master!
I0620 00:07:38.876588 32129 master.cpp:908] Recovering from registrar
I0620 00:07:38.876657 32128 registrar.cpp:313] Recovering registrar
I0620 00:07:38.876742 32129 master.cpp:817] Dropping 'mesos.internal.AuthenticateMessage' message since not recovered yet
I0620 00:07:38.876799 32123 detector.cpp:382] A new leading master (UPID=master@67.195.138.61:60427) is detected
I0620 00:07:38.876893 32124 slave.cpp:581] New master detected at master@67.195.138.61:60427
I0620 00:07:38.876924 32124 slave.cpp:657] Authenticating with master master@67.195.138.61:60427
I0620 00:07:38.876930 32128 log.cpp:656] Attempting to start the writer
I0620 00:07:38.876950 32123 status_update_manager.cpp:167] New master detected at master@67.195.138.61:60427
I0620 00:07:38.877017 32124 slave.cpp:630] Detecting new master
I0620 00:07:38.877028 32128 authenticatee.hpp:128] Creating new client SASL connection
I0620 00:07:38.877198 32125 master.cpp:817] Dropping 'mesos.internal.AuthenticateMessage' message since not recovered yet
I0620 00:07:38.877509 32126 replica.cpp:474] Replica received implicit promise request with proposal 2
I0620 00:07:38.926470 32126 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 48.942865ms
I0620 00:07:38.926494 32126 replica.cpp:342] Persisted promised to 2
I0620 00:07:38.926798 32123 coordinator.cpp:230] Coordinator attemping to fill missing position
I0620 00:07:38.926941 32130 log.cpp:672] Writer started with ending position 4
I0620 00:07:38.927387 32129 leveldb.cpp:438] Reading position from leveldb took 36862ns
I0620 00:07:38.927423 32129 leveldb.cpp:438] Reading position from leveldb took 11429ns
I0620 00:07:38.927918 32125 registrar.cpp:346] Successfully fetched the registry (289B)
I0620 00:07:38.927953 32125 registrar.cpp:422] Attempting to update the 'registry'
I0620 00:07:38.929901 32126 log.cpp:680] Attempting to append 328 bytes to the log
I0620 00:07:38.929966 32123 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 5
I0620 00:07:38.930323 32129 replica.cpp:508] Replica received write request for position 5
I0620 00:07:38.939896 32129 leveldb.cpp:343] Persisting action (347 bytes) to leveldb took 9.553736ms
I0620 00:07:38.939921 32129 replica.cpp:676] Persisted action at 5
I0620 00:07:38.940250 32126 replica.cpp:655] Replica received learned notice for position 5
I0620 00:07:38.948253 32126 leveldb.cpp:343] Persisting action (349 bytes) to leveldb took 7.982294ms
I0620 00:07:38.948278 32126 replica.cpp:676] Persisted action at 5
I0620 00:07:38.948289 32126 replica.cpp:661] Replica learned APPEND action at position 5
I0620 00:07:38.948734 32123 registrar.cpp:479] Successfully updated 'registry'
I0620 00:07:38.948824 32126 log.cpp:699] Attempting to truncate the log to 5
I0620 00:07:38.948897 32128 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 6
I0620 00:07:38.948912 32123 registrar.cpp:372] Successfully recovered registrar
I0620 00:07:38.949233 32125 master.cpp:935] Recovered 1 slaves from the Registry (289B) ; allowing 10mins for slaves to re-register
I0620 00:07:38.949322 32126 replica.cpp:508] Replica received write request for position 6
I0620 00:07:38.956557 32126 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 7.132774ms
I0620 00:07:38.956575 32126 replica.cpp:676] Persisted action at 6
I0620 00:07:38.956833 32129 replica.cpp:655] Replica received learned notice for position 6
I0620 00:07:38.964882 32129 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 8.02974ms
I0620 00:07:38.964915 32129 leveldb.cpp:401] Deleting ~2 keys from leveldb took 14883ns
I0620 00:07:38.964926 32129 replica.cpp:676] Persisted action at 6
I0620 00:07:38.964936 32129 replica.cpp:661] Replica learned TRUNCATE action at position 6
I0620 00:07:39.839997 32128 hierarchical_allocator_process.hpp:724] No resources available to allocate!
I0620 00:07:39.840025 32128 hierarchical_allocator_process.hpp:686] Performed allocation for 0 slaves in 45415ns
I0620 00:07:40.840428 32130 hierarchical_allocator_process.hpp:724] No resources available to allocate!
I0620 00:07:40.840445 32130 hierarchical_allocator_process.hpp:686] Performed allocation for 0 slaves in 44701ns
2014-06-20 00:07:41,280:32101(0x2b3ef155d700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:55383] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I0620 00:07:41.841348 32126 hierarchical_allocator_process.hpp:724] No resources available to allocate!
I0620 00:07:41.841375 32126 hierarchical_allocator_process.hpp:686] Performed allocation for 0 slaves in 46186ns
I0620 00:07:42.842380 32128 hierarchical_allocator_process.hpp:724] No resources available to allocate!
I0620 00:07:42.842408 32128 hierarchical_allocator_process.hpp:686] Performed allocation for 0 slaves in 42430ns
I0620 00:07:43.838938 32124 master.cpp:120] No whitelist given. Advertising offers for all slaves
I0620 00:07:43.843060 32126 hierarchical_allocator_process.hpp:724] No resources available to allocate!
I0620 00:07:43.843081 32126 hierarchical_allocator_process.hpp:686] Performed allocation for 0 slaves in 36053ns
W0620 00:07:43.877221 32129 sched.cpp:380] Authentication timed out
W0620 00:07:43.877256 32123 slave.cpp:731] Authentication timed out
I0620 00:07:43.877368 32129 sched.cpp:340] Failed to authenticate with master master@67.195.138.61:60427: Authentication discarded
W0620 00:07:43.877374 32123 slave.cpp:695] Failed to authenticate with master master@67.195.138.61:60427: Authentication discarded
I0620 00:07:43.877424 32129 sched.cpp:285] Authenticating with master master@67.195.138.61:60427
I0620 00:07:43.877439 32123 slave.cpp:657] Authenticating with master master@67.195.138.61:60427
I0620 00:07:43.877563 32125 authenticatee.hpp:128] Creating new client SASL connection
I0620 00:07:43.877640 32130 authenticatee.hpp:128] Creating new client SASL connection
I0620 00:07:43.877792 32125 master.cpp:3457] Authenticating scheduler-e7396230-b44b-499a-8088-ffb966f5dc6c@67.195.138.61:60427
I0620 00:07:43.877885 32123 authenticator.hpp:156] Creating new server SASL connection
I0620 00:07:43.877923 32125 master.cpp:3457] Authenticating slave(186)@67.195.138.61:60427
I0620 00:07:43.878028 32129 authenticator.hpp:156] Creating new server SASL connection
I0620 00:07:43.878029 32126 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0620 00:07:43.878070 32126 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0620 00:07:43.878123 32126 authenticator.hpp:262] Received SASL authentication start
I0620 00:07:43.878150 32123 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0620 00:07:43.878170 32123 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0620 00:07:43.878206 32126 authenticator.hpp:384] Authentication requires more steps
I0620 00:07:43.878208 32123 authenticator.hpp:262] Received SASL authentication start
I0620 00:07:43.878240 32126 authenticatee.hpp:265] Received SASL authentication step
I0620 00:07:43.878250 32123 authenticator.hpp:384] Authentication requires more steps
I0620 00:07:43.878284 32123 authenticatee.hpp:265] Received SASL authentication step
I0620 00:07:43.878296 32126 authenticator.hpp:290] Received SASL authentication step
I0620 00:07:43.878319 32126 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0620 00:07:43.878324 32123 authenticator.hpp:290] Received SASL authentication step
I0620 00:07:43.878329 32126 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0620 00:07:43.878347 32123 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0620 00:07:43.878350 32126 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0620 00:07:43.878360 32123 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0620 00:07:43.878373 32126 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0620 00:07:43.878381 32123 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0620 00:07:43.878382 32126 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0620 00:07:43.878396 32123 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0620 00:07:43.878398 32126 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0620 00:07:43.878407 32123 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0620 00:07:43.878424 32123 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0620 00:07:43.878424 32126 authenticator.hpp:376] Authentication success
I0620 00:07:43.878438 32123 authenticator.hpp:376] Authentication success
I0620 00:07:43.878512 32130 authenticatee.hpp:305] Authentication success
I0620 00:07:43.878530 32123 authenticatee.hpp:305] Authentication success
I0620 00:07:43.878547 32126 master.cpp:3497] Successfully authenticated principal 'test-principal' at slave(186)@67.195.138.61:60427
I0620 00:07:43.878638 32130 sched.cpp:359] Successfully authenticated with master master@67.195.138.61:60427
I0620 00:07:43.878654 32130 sched.cpp:478] Sending registration request to master@67.195.138.61:60427
I0620 00:07:43.878690 32126 master.cpp:3497] Successfully authenticated principal 'test-principal' at scheduler-e7396230-b44b-499a-8088-ffb966f5dc6c@67.195.138.61:60427
I0620 00:07:43.878718 32123 slave.cpp:714] Successfully authenticated with master master@67.195.138.61:60427
I0620 00:07:43.878779 32126 master.cpp:1304] Received re-registration request from framework 20140620-000738-1032504131-60427-32101-0000 at scheduler-e7396230-b44b-499a-8088-ffb966f5dc6c@67.195.138.61:60427
I0620 00:07:43.878809 32126 master.cpp:1156] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0620 00:07:43.878820 32123 slave.cpp:952] Will retry registration in 16.152642ms if necessary
I0620 00:07:43.878953 32126 master.cpp:1355] Re-registering framework 20140620-000738-1032504131-60427-32101-0000 at scheduler-e7396230-b44b-499a-8088-ffb966f5dc6c@67.195.138.61:60427
I0620 00:07:43.879030 32123 sched.cpp:409] Framework registered with 20140620-000738-1032504131-60427-32101-0000
I0620 00:07:43.879060 32123 sched.cpp:423] Scheduler::registered took 12083ns
I0620 00:07:43.879140 32130 hierarchical_allocator_process.hpp:331] Added framework 20140620-000738-1032504131-60427-32101-0000
I0620 00:07:43.879153 32130 hierarchical_allocator_process.hpp:724] No resources available to allocate!
I0620 00:07:43.879159 32130 hierarchical_allocator_process.hpp:686] Performed allocation for 0 slaves in 7877ns
I0620 00:07:43.896078 32124 slave.cpp:952] Will retry registration in 38.269216ms if necessary
I0620 00:07:43.896163 32128 master.cpp:2911] Re-registering slave 20140620-000738-1032504131-60427-32101-0 at slave(186)@67.195.138.61:60427 (juno.apache.org)
I0620 00:07:43.896338 32130 registrar.cpp:422] Attempting to update the 'registry'
I0620 00:07:43.898275 32128 log.cpp:680] Attempting to append 328 bytes to the log
I0620 00:07:43.898355 32123 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 7
I0620 00:07:43.898670 32128 replica.cpp:508] Replica received write request for position 7
I0620 00:07:43.934613 32128 leveldb.cpp:343] Persisting action (347 bytes) to leveldb took 35.919746ms
I0620 00:07:43.934651 32128 replica.cpp:676] Persisted action at 7
I0620 00:07:43.934933 32125 replica.cpp:655] Replica received learned notice for position 7
I0620 00:07:43.935358 32126 slave.cpp:952] Will retry registration in 55.403726ms if necessary
I0620 00:07:43.935402 32123 master.cpp:2904] Ignoring re-register slave message from slave 20140620-000738-1032504131-60427-32101-0 at slave(186)@67.195.138.61:60427 (juno.apache.org) as readmission is already in progress
I0620 00:07:43.965859 32125 leveldb.cpp:343] Persisting action (349 bytes) to leveldb took 30.900736ms
I0620 00:07:43.965889 32125 replica.cpp:676] Persisted action at 7
I0620 00:07:43.965900 32125 replica.cpp:661] Replica learned APPEND action at position 7
I0620 00:07:43.966294 32127 registrar.cpp:479] Successfully updated 'registry'
I0620 00:07:43.966370 32123 log.cpp:699] Attempting to truncate the log to 7
I0620 00:07:43.966464 32129 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 8
I0620 00:07:43.966533 32123 master.cpp:2962] Re-registered slave 20140620-000738-1032504131-60427-32101-0 at slave(186)@67.195.138.61:60427 (juno.apache.org)
I0620 00:07:43.966555 32123 master.cpp:3923] Adding slave 20140620-000738-1032504131-60427-32101-0 at slave(186)@67.195.138.61:60427 (juno.apache.org) with cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000]
I0620 00:07:43.966677 32123 master.hpp:757] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 20140620-000738-1032504131-60427-32101-0 (juno.apache.org)
I0620 00:07:43.966701 32126 slave.cpp:798] Re-registered with master master@67.195.138.61:60427
I0620 00:07:43.966706 32128 replica.cpp:508] Replica received write request for position 8
I0620 00:07:43.966830 32125 slave.cpp:1564] Updating framework 20140620-000738-1032504131-60427-32101-0000 pid to scheduler-e7396230-b44b-499a-8088-ffb966f5dc6c@67.195.138.61:60427
I0620 00:07:43.966999 32123 hierarchical_allocator_process.hpp:444] Added slave 20140620-000738-1032504131-60427-32101-0 (juno.apache.org) with cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000] (and cpus(*):1; mem(*):524; disk(*):23038; ports(*):[31000-32000] available)
I0620 00:07:43.967062 32123 hierarchical_allocator_process.hpp:750] Offering cpus(*):1; mem(*):524; disk(*):23038; ports(*):[31000-32000] on slave 20140620-000738-1032504131-60427-32101-0 to framework 20140620-000738-1032504131-60427-32101-0000
I0620 00:07:43.967207 32123 hierarchical_allocator_process.hpp:706] Performed allocation for slave 20140620-000738-1032504131-60427-32101-0 in 173621ns
I0620 00:07:43.967272 32129 master.hpp:785] Adding offer 20140620-000738-1032504131-60427-32101-0 with resources cpus(*):1; mem(*):524; disk(*):23038; ports(*):[31000-32000] on slave 20140620-000738-1032504131-60427-32101-0 (juno.apache.org)
I0620 00:07:43.967332 32129 master.cpp:3404] Sending 1 offers to framework 20140620-000738-1032504131-60427-32101-0000
I0620 00:07:43.967478 32130 sched.cpp:546] Scheduler::resourceOffers took 24002ns
I0620 00:07:43.967653 32126 sched.cpp:747] Stopping framework '20140620-000738-1032504131-60427-32101-0000'
I0620 00:07:43.967767 32101 master.cpp:610] Master terminating
I0620 00:07:43.967823 32101 master.hpp:775] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 20140620-000738-1032504131-60427-32101-0 (juno.apache.org)
W0620 00:07:43.967872 32101 master.cpp:4209] Removing task 0 of framework 20140620-000738-1032504131-60427-32101-0000 and slave 20140620-000738-1032504131-60427-32101-0 in non-terminal state TASK_RUNNING
I0620 00:07:43.967941 32101 master.hpp:795] Removing offer 20140620-000738-1032504131-60427-32101-0 with resources cpus(*):1; mem(*):524; disk(*):23038; ports(*):[31000-32000] on slave 20140620-000738-1032504131-60427-32101-0 (juno.apache.org)
I0620 00:07:43.968018 32126 hierarchical_allocator_process.hpp:635] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):1; mem(*):500) on slave 20140620-000738-1032504131-60427-32101-0 from framework 20140620-000738-1032504131-60427-32101-0000
I0620 00:07:43.968104 32125 slave.cpp:2311] master@67.195.138.61:60427 exited
W0620 00:07:43.968132 32125 slave.cpp:2314] Master disconnected! Waiting for a new master to be elected
2014-06-20 00:07:43,970:32101(0x2b3d5a938700):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x146b699804c0011 to [127.0.0.1:59486]
2014-06-20 00:07:43,970:32101(0x2b3d5a12ff80):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x146b699804c0012 to [127.0.0.1:59486]
I0620 00:07:43.979182 32128 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 12.440455ms
I0620 00:07:43.979205 32128 replica.cpp:676] Persisted action at 8
I0620 00:07:43.979532 32101 contender.cpp:186] Now cancelling the membership: 4
I0620 00:07:43.979634 32123 group.cpp:619] Trying to remove '/znode/info_0000000004' in ZooKeeper
2014-06-20 00:07:43,997:32101(0x2b3d5a12ff80):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x146b699804c0013 to [127.0.0.1:59486]
I0620 00:07:43.997586 32125 group.cpp:714] Found non-sequence node 'log_replicas' at '/znode' in ZooKeeper
I0620 00:07:43.997737 32129 group.cpp:714] Found non-sequence node 'log_replicas' at '/znode' in ZooKeeper
2014-06-20 00:07:43,997:32101(0x2b3d5a12ff80):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x146b699804c0010 to [127.0.0.1:59486]
I0620 00:07:43.997799 32128 detector.cpp:126] The current leader (id=4) is lost
I0620 00:07:43.997818 32128 detector.cpp:138] Detected a new leader: None
I0620 00:07:43.998049 32123 slave.cpp:2507] Executor 'default' of framework 20140620-000738-1032504131-60427-32101-0000 has exited with status 0
I0620 00:07:44.001626 32123 slave.cpp:2068] Handling status update TASK_LOST (UUID: 9c73d023-ace9-45ff-9b75-072270d34bca) for task 0 of framework 20140620-000738-1032504131-60427-32101-0000 from @0.0.0.0:0
I0620 00:07:44.001663 32123 slave.cpp:3754] Terminating task 0
I0620 00:07:44.001782 32123 slave.cpp:466] Slave terminating
I0620 00:07:44.001798 32123 slave.cpp:1387] Asked to shut down framework 20140620-000738-1032504131-60427-32101-0000 by @0.0.0.0:0
I0620 00:07:44.001809 32123 slave.cpp:1412] Shutting down framework 20140620-000738-1032504131-60427-32101-0000
I0620 00:07:44.001822 32123 slave.cpp:2646] Cleaning up executor 'default' of framework 20140620-000738-1032504131-60427-32101-0000
I0620 00:07:44.001938 32124 gc.cpp:56] Scheduling '/tmp/AllocatorZooKeeperTest_0_FrameworkReregistersFirst_LW6RNz/slaves/20140620-000738-1032504131-60427-32101-0/frameworks/20140620-000738-1032504131-60427-32101-0000/executors/default/runs/5b303000-f5d9-4de7-bf24-992fc3cca382' for gc 6.99998840417778days in the future
I0620 00:07:44.001957 32123 slave.cpp:2721] Cleaning up framework 20140620-000738-1032504131-60427-32101-0000
I0620 00:07:44.001997 32124 gc.cpp:56] Scheduling '/tmp/AllocatorZooKeeperTest_0_FrameworkReregistersFirst_LW6RNz/slaves/20140620-000738-1032504131-60427-32101-0/frameworks/20140620-000738-1032504131-60427-32101-0000/executors/default' for gc 6.99998840350815days in the future
I0620 00:07:44.002017 32125 status_update_manager.cpp:282] Closing status update streams for framework 20140620-000738-1032504131-60427-32101-0000
I0620 00:07:44.002043 32125 status_update_manager.cpp:530] Cleaning up status update stream for task 0 of framework 20140620-000738-1032504131-60427-32101-0000
I0620 00:07:44.002038 32124 gc.cpp:56] Scheduling '/tmp/AllocatorZooKeeperTest_0_FrameworkReregistersFirst_LW6RNz/slaves/20140620-000738-1032504131-60427-32101-0/frameworks/20140620-000738-1032504131-60427-32101-0000' for gc 6.99998840272days in the future
I0620 00:07:44.004887 32127 group.cpp:714] Found non-sequence node 'log_replicas' at '/znode' in ZooKeeper
2014-06-20 00:07:44,005:32101(0x2b3d5a12ff80):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x146b699804c000e to [127.0.0.1:59486]
2014-06-20 00:07:44,005:32101(0x2b3d5a335700):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x146b699804c000f to [127.0.0.1:59486]
[ OK ] AllocatorZooKeeperTest/0.FrameworkReregistersFirst (5715 ms)
I0620 00:07:44.013337 32101 zookeeper_test_server.cpp:122] Shutdown ZooKeeperTestServer on port 59486
[----------] 2 tests from AllocatorZooKeeperTest/0 (12344 ms total)
[----------] Global test environment tear-down
[==========] 377 tests from 62 test cases ran. (328748 ms total)
[ PASSED ] 376 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] AllocatorZooKeeperTest/0.SlaveReregistersFirst, where TypeParam = mesos::internal::master::allocator::HierarchicalAllocatorProcess<mesos::internal::master::allocator::DRFSorter, mesos::internal::master::allocator::DRFSorter>
1 FAILED TEST
YOU HAVE 3 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `<https://builds.apache.org/job/Mesos-Ubuntu-distcheck/ws/build/mesos-0.20.0/_build/src'>
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Ubuntu-distcheck/ws/build/mesos-0.20.0/_build/src'>
make[2]: *** [check] Error 2
make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Ubuntu-distcheck/ws/build/mesos-0.20.0/_build/src'>
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Ubuntu-distcheck/ws/build/mesos-0.20.0/_build'>
make: *** [distcheck] Error 1
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos-Ubuntu-distcheck #163
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Ubuntu-distcheck/163/changes>
Build failed in Jenkins: Mesos-Ubuntu-distcheck #162
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Ubuntu-distcheck/162/changes>
Changes:
[bmahler] Exposed method in Process to get event counts of specific types.
[bmahler] Exposed MessageEvent queue size from Master/Scheduler.
------------------------------------------
[...truncated 57970 lines...]
I0620 02:25:49.649246 25765 replica.cpp:508] Replica received write request for position 2
I0620 02:25:49.649292 25767 replica.cpp:508] Replica received write request for position 2
I0620 02:25:49.670907 25765 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 21.647992ms
I0620 02:25:49.670930 25765 replica.cpp:676] Persisted action at 2
I0620 02:25:49.671282 25767 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 21.976825ms
I0620 02:25:49.671303 25767 replica.cpp:676] Persisted action at 2
I0620 02:25:49.671464 25767 replica.cpp:655] Replica received learned notice for position 2
I0620 02:25:49.671470 25764 replica.cpp:655] Replica received learned notice for position 2
I0620 02:25:49.689733 25767 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 18.250736ms
I0620 02:25:49.689775 25767 leveldb.cpp:401] Deleting ~1 keys from leveldb took 16979ns
I0620 02:25:49.689788 25767 replica.cpp:676] Persisted action at 2
I0620 02:25:49.689798 25767 replica.cpp:661] Replica learned TRUNCATE action at position 2
I0620 02:25:49.690085 25764 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 18.598298ms
I0620 02:25:49.690129 25764 leveldb.cpp:401] Deleting ~1 keys from leveldb took 22096ns
I0620 02:25:49.690139 25768 log.cpp:680] Attempting to append 167 bytes to the log
I0620 02:25:49.690141 25764 replica.cpp:676] Persisted action at 2
I0620 02:25:49.690171 25764 replica.cpp:661] Replica learned TRUNCATE action at position 2
I0620 02:25:49.690191 25764 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3
I0620 02:25:49.690498 25770 replica.cpp:508] Replica received write request for position 3
I0620 02:25:49.690577 25764 replica.cpp:508] Replica received write request for position 3
I0620 02:25:49.705569 25770 leveldb.cpp:343] Persisting action (186 bytes) to leveldb took 15.048121ms
I0620 02:25:49.705595 25770 replica.cpp:676] Persisted action at 3
I0620 02:25:49.705945 25764 leveldb.cpp:343] Persisting action (186 bytes) to leveldb took 15.351493ms
I0620 02:25:49.705963 25764 replica.cpp:676] Persisted action at 3
I0620 02:25:49.706161 25766 replica.cpp:655] Replica received learned notice for position 3
I0620 02:25:49.706162 25768 replica.cpp:655] Replica received learned notice for position 3
I0620 02:25:49.723018 25768 leveldb.cpp:343] Persisting action (188 bytes) to leveldb took 16.822402ms
I0620 02:25:49.723042 25768 replica.cpp:676] Persisted action at 3
I0620 02:25:49.723052 25768 replica.cpp:661] Replica learned APPEND action at position 3
I0620 02:25:49.723348 25770 registrar.cpp:479] Successfully updated 'registry'
I0620 02:25:49.723397 25770 registrar.cpp:422] Attempting to update the 'registry'
I0620 02:25:49.723423 25765 log.cpp:699] Attempting to truncate the log to 3
I0620 02:25:49.723470 25766 leveldb.cpp:343] Persisting action (188 bytes) to leveldb took 17.284295ms
I0620 02:25:49.723494 25766 replica.cpp:676] Persisted action at 3
I0620 02:25:49.723502 25766 replica.cpp:661] Replica learned APPEND action at position 3
I0620 02:25:49.723558 25768 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4
I0620 02:25:49.723776 25768 replica.cpp:508] Replica received write request for position 4
I0620 02:25:49.723811 25771 replica.cpp:508] Replica received write request for position 4
I0620 02:25:49.738881 25768 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 15.089865ms
I0620 02:25:49.738901 25768 replica.cpp:676] Persisted action at 4
I0620 02:25:49.739262 25771 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 15.434135ms
I0620 02:25:49.739285 25771 replica.cpp:676] Persisted action at 4
I0620 02:25:49.739441 25765 replica.cpp:655] Replica received learned notice for position 4
I0620 02:25:49.739442 25771 replica.cpp:655] Replica received learned notice for position 4
I0620 02:25:49.756337 25765 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 16.866874ms
I0620 02:25:49.756381 25765 leveldb.cpp:401] Deleting ~2 keys from leveldb took 19920ns
I0620 02:25:49.756393 25765 replica.cpp:676] Persisted action at 4
I0620 02:25:49.756402 25765 replica.cpp:661] Replica learned TRUNCATE action at position 4
I0620 02:25:49.756636 25765 log.cpp:680] Attempting to append 146 bytes to the log
I0620 02:25:49.756670 25765 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 5
I0620 02:25:49.756866 25765 replica.cpp:508] Replica received write request for position 5
I0620 02:25:49.763875 25771 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 24.401377ms
I0620 02:25:49.763913 25771 leveldb.cpp:401] Deleting ~2 keys from leveldb took 18743ns
I0620 02:25:49.763926 25771 replica.cpp:676] Persisted action at 4
I0620 02:25:49.763936 25771 replica.cpp:661] Replica learned TRUNCATE action at position 4
I0620 02:25:49.763948 25771 replica.cpp:508] Replica received write request for position 5
I0620 02:25:49.764338 25765 leveldb.cpp:343] Persisting action (165 bytes) to leveldb took 7.459108ms
I0620 02:25:49.764356 25765 replica.cpp:676] Persisted action at 5
I0620 02:25:49.772986 25771 leveldb.cpp:343] Persisting action (165 bytes) to leveldb took 9.026527ms
I0620 02:25:49.773005 25771 replica.cpp:676] Persisted action at 5
I0620 02:25:49.773154 25768 replica.cpp:655] Replica received learned notice for position 5
I0620 02:25:49.773164 25765 replica.cpp:655] Replica received learned notice for position 5
I0620 02:25:49.789671 25768 leveldb.cpp:343] Persisting action (167 bytes) to leveldb took 16.502303ms
I0620 02:25:49.789690 25768 replica.cpp:676] Persisted action at 5
I0620 02:25:49.789700 25768 replica.cpp:661] Replica learned APPEND action at position 5
I0620 02:25:49.790042 25765 leveldb.cpp:343] Persisting action (167 bytes) to leveldb took 16.866008ms
I0620 02:25:49.790061 25765 replica.cpp:676] Persisted action at 5
I0620 02:25:49.790069 25765 replica.cpp:661] Replica learned APPEND action at position 5
I0620 02:25:49.790307 25765 registrar.cpp:479] Successfully updated 'registry'
I0620 02:25:49.790362 25765 log.cpp:699] Attempting to truncate the log to 5
I0620 02:25:49.790403 25765 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 6
I0620 02:25:49.790611 25765 replica.cpp:508] Replica received write request for position 6
I0620 02:25:49.790674 25764 replica.cpp:508] Replica received write request for position 6
I0620 02:25:49.805522 25765 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 14.885207ms
I0620 02:25:49.805543 25765 replica.cpp:676] Persisted action at 6
I0620 02:25:49.805894 25764 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 15.204254ms
I0620 02:25:49.805925 25764 replica.cpp:676] Persisted action at 6
[ OK ] Strict/RegistrarTest.recover/0 (862 ms)
[----------] 16 tests from Strict/RegistrarTest (13711 ms total)
[----------] 7 tests from InMemoryStateTest
[ RUN ] InMemoryStateTest.FetchAndStoreAndStoreAndFetch
[ OK ] InMemoryStateTest.FetchAndStoreAndStoreAndFetch (5 ms)
[ RUN ] InMemoryStateTest.FetchAndStoreAndExpungeAndExpunge
[ OK ] InMemoryStateTest.FetchAndStoreAndExpungeAndExpunge (3 ms)
[ RUN ] InMemoryStateTest.Names
[ OK ] InMemoryStateTest.Names (3 ms)
[ RUN ] InMemoryStateTest.FetchAndStoreAndFetch
[ OK ] InMemoryStateTest.FetchAndStoreAndFetch (3 ms)
[ RUN ] InMemoryStateTest.FetchAndStoreAndExpungeAndStoreAndFetch
[ OK ] InMemoryStateTest.FetchAndStoreAndExpungeAndStoreAndFetch (4 ms)
[ RUN ] InMemoryStateTest.FetchAndStoreAndStoreFailAndFetch
[ OK ] InMemoryStateTest.FetchAndStoreAndStoreFailAndFetch (4 ms)
[ RUN ] InMemoryStateTest.FetchAndStoreAndExpungeAndFetch
[ OK ] InMemoryStateTest.FetchAndStoreAndExpungeAndFetch (4 ms)
[----------] 7 tests from InMemoryStateTest (26 ms total)
[----------] 7 tests from MesosContainerizerProcessTest
[ RUN ] MesosContainerizerProcessTest.NoExtractExecutable
[ OK ] MesosContainerizerProcessTest.NoExtractExecutable (1 ms)
[ RUN ] MesosContainerizerProcessTest.MultipleURIs
[ OK ] MesosContainerizerProcessTest.MultipleURIs (0 ms)
[ RUN ] MesosContainerizerProcessTest.Simple
[ OK ] MesosContainerizerProcessTest.Simple (0 ms)
[ RUN ] MesosContainerizerProcessTest.EmptyHadoop
[ OK ] MesosContainerizerProcessTest.EmptyHadoop (0 ms)
[ RUN ] MesosContainerizerProcessTest.NoHadoop
[ OK ] MesosContainerizerProcessTest.NoHadoop (1 ms)
[ RUN ] MesosContainerizerProcessTest.NoExtract
[ OK ] MesosContainerizerProcessTest.NoExtract (0 ms)
[ RUN ] MesosContainerizerProcessTest.NoUser
[ OK ] MesosContainerizerProcessTest.NoUser (0 ms)
[----------] 7 tests from MesosContainerizerProcessTest (2 ms total)
[----------] 1 test from HealthTest
[ RUN ] HealthTest.ObserveEndpoint
Using temporary directory '/tmp/HealthTest_ObserveEndpoint_hR4hgs'
I0620 02:25:49.917611 25609 leveldb.cpp:176] Opened db in 82.319875ms
I0620 02:25:49.920944 25609 leveldb.cpp:183] Compacted db in 3.308373ms
I0620 02:25:49.920965 25609 leveldb.cpp:198] Created db iterator in 4521ns
I0620 02:25:49.920975 25609 leveldb.cpp:204] Seeked to beginning of db in 684ns
I0620 02:25:49.920984 25609 leveldb.cpp:273] Iterated through 0 keys in the db in 210ns
I0620 02:25:49.920999 25609 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0620 02:25:49.921480 25766 recover.cpp:425] Starting replica recovery
I0620 02:25:49.921636 25767 recover.cpp:451] Replica is in EMPTY status
I0620 02:25:49.922830 25767 replica.cpp:638] Replica in EMPTY status received a broadcasted recover request
I0620 02:25:49.922976 25765 recover.cpp:188] Received a recover response from a replica in EMPTY status
I0620 02:25:49.923215 25771 master.cpp:286] Master 20140620-022549-1015726915-43172-25609 (janus.apache.org) started on 67.195.138.60:43172
I0620 02:25:49.923238 25771 master.cpp:323] Master only allowing authenticated frameworks to register
I0620 02:25:49.923246 25771 master.cpp:328] Master only allowing authenticated slaves to register
I0620 02:25:49.923256 25771 credentials.hpp:35] Loading credentials for authentication from '/tmp/HealthTest_ObserveEndpoint_hR4hgs/credentials'
I0620 02:25:49.923339 25765 recover.cpp:542] Updating replica status to STARTING
I0620 02:25:49.923341 25771 master.cpp:354] Authorization enabled
I0620 02:25:49.923888 25769 hierarchical_allocator_process.hpp:301] Initializing hierarchical allocator process with master : master@67.195.138.60:43172
I0620 02:25:49.923964 25769 master.cpp:120] No whitelist given. Advertising offers for all slaves
I0620 02:25:49.924254 25771 master.cpp:1077] The newly elected leader is master@67.195.138.60:43172 with id 20140620-022549-1015726915-43172-25609
I0620 02:25:49.924269 25771 master.cpp:1090] Elected as the leading master!
I0620 02:25:49.924278 25771 master.cpp:908] Recovering from registrar
I0620 02:25:49.924335 25767 registrar.cpp:313] Recovering registrar
I0620 02:25:49.951181 25765 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 27.76096ms
I0620 02:25:49.951203 25765 replica.cpp:320] Persisted replica status to STARTING
I0620 02:25:49.951320 25766 recover.cpp:451] Replica is in STARTING status
I0620 02:25:49.951642 25769 replica.cpp:638] Replica in STARTING status received a broadcasted recover request
I0620 02:25:49.951741 25767 recover.cpp:188] Received a recover response from a replica in STARTING status
I0620 02:25:49.951912 25771 recover.cpp:542] Updating replica status to VOTING
I0620 02:25:49.959229 25767 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 7.253842ms
I0620 02:25:49.959251 25767 replica.cpp:320] Persisted replica status to VOTING
I0620 02:25:49.959311 25769 recover.cpp:556] Successfully joined the Paxos group
I0620 02:25:49.959417 25769 recover.cpp:440] Recover process terminated
I0620 02:25:49.959590 25764 log.cpp:656] Attempting to start the writer
I0620 02:25:49.960114 25769 replica.cpp:474] Replica received implicit promise request with proposal 1
I0620 02:25:49.967551 25769 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 7.420095ms
I0620 02:25:49.967571 25769 replica.cpp:342] Persisted promised to 1
I0620 02:25:49.967782 25769 coordinator.cpp:230] Coordinator attemping to fill missing position
I0620 02:25:49.968286 25768 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2
I0620 02:25:49.975890 25768 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 7.585935ms
I0620 02:25:49.975915 25768 replica.cpp:676] Persisted action at 0
I0620 02:25:49.976368 25770 replica.cpp:508] Replica received write request for position 0
I0620 02:25:49.976395 25770 leveldb.cpp:438] Reading position from leveldb took 11193ns
I0620 02:25:49.984212 25770 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 7.802325ms
I0620 02:25:49.984232 25770 replica.cpp:676] Persisted action at 0
I0620 02:25:49.984498 25765 replica.cpp:655] Replica received learned notice for position 0
2014-06-20 02:25:49,989:25609(0x2b8614200700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:59010] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I0620 02:25:49.992544 25765 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 8.029023ms
I0620 02:25:49.992563 25765 replica.cpp:676] Persisted action at 0
I0620 02:25:49.992573 25765 replica.cpp:661] Replica learned NOP action at position 0
I0620 02:25:49.992781 25764 log.cpp:672] Writer started with ending position 0
I0620 02:25:49.993186 25766 leveldb.cpp:438] Reading position from leveldb took 8235ns
I0620 02:25:49.994684 25764 registrar.cpp:346] Successfully fetched the registry (0B)
I0620 02:25:49.994709 25764 registrar.cpp:422] Attempting to update the 'registry'
I0620 02:25:49.996083 25764 log.cpp:680] Attempting to append 138 bytes to the log
I0620 02:25:49.996136 25764 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1
I0620 02:25:49.996374 25764 replica.cpp:508] Replica received write request for position 1
I0620 02:25:50.005136 25764 leveldb.cpp:343] Persisting action (157 bytes) to leveldb took 8.748084ms
I0620 02:25:50.005156 25764 replica.cpp:676] Persisted action at 1
I0620 02:25:50.005358 25764 replica.cpp:655] Replica received learned notice for position 1
I0620 02:25:50.013437 25764 leveldb.cpp:343] Persisting action (159 bytes) to leveldb took 8.065646ms
I0620 02:25:50.013455 25764 replica.cpp:676] Persisted action at 1
I0620 02:25:50.013464 25764 replica.cpp:661] Replica learned APPEND action at position 1
I0620 02:25:50.013749 25764 registrar.cpp:479] Successfully updated 'registry'
I0620 02:25:50.013787 25764 registrar.cpp:372] Successfully recovered registrar
I0620 02:25:50.013833 25764 log.cpp:699] Attempting to truncate the log to 1
I0620 02:25:50.013906 25764 master.cpp:935] Recovered 0 slaves from the Registry (100B) ; allowing 10mins for slaves to re-register
I0620 02:25:50.013960 25764 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2
I0620 02:25:50.014220 25764 replica.cpp:508] Replica received write request for position 2
I0620 02:25:50.014370 25770 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.014430 25770 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.014811 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.015219 25768 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.015300 25768 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.015509 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.015856 25768 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.015909 25768 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.016111 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.016470 25766 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.016525 25766 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.016736 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.017094 25769 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.017225 25769 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.017428 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.017789 25767 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.017843 25767 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.018107 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.018426 25771 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.018483 25771 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.018717 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.019074 25765 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.019145 25765 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.019425 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.019775 25768 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.019826 25768 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.020081 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.020478 25767 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.020601 25767 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.020862 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.021236 25767 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.021296 25767 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.021550 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.021950 25770 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.022016 25770 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.022253 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.022608 25766 process.cpp:3335] Handling HTTP event for process 'master' with path: '/master/observe'
I0620 02:25:50.022670 25766 http.cpp:258] HTTP request for '/master/observe'
I0620 02:25:50.022900 25772 process.cpp:1037] Socket closed while receiving
I0620 02:25:50.023136 25609 master.cpp:610] Master terminating
I0620 02:25:50.029005 25764 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 14.738799ms
I0620 02:25:50.029032 25764 replica.cpp:676] Persisted action at 2
[ OK ] HealthTest.ObserveEndpoint (195 ms)
[----------] 1 test from HealthTest (195 ms total)
[----------] Global test environment tear-down
[==========] 377 tests from 62 test cases ran. (334352 ms total)
[ PASSED ] 376 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ExamplesTest.PythonFramework
1 FAILED TEST
YOU HAVE 3 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `<https://builds.apache.org/job/Mesos-Ubuntu-distcheck/ws/build/mesos-0.20.0/_build/src'>
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Ubuntu-distcheck/ws/build/mesos-0.20.0/_build/src'>
make[2]: *** [check] Error 2
make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Ubuntu-distcheck/ws/build/mesos-0.20.0/_build/src'>
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Ubuntu-distcheck/ws/build/mesos-0.20.0/_build'>
make: *** [distcheck] Error 1
Build step 'Execute shell' marked build as failure