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/07/29 09:07:13 UTC
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME #2016
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/2016/changes>
Changes:
[yujie.jay] Fixed a bug in port mapping test cleanup function.
------------------------------------------
[...truncated 60519 lines...]
I0729 07:07:11.393757 2566 recover.cpp:451] Replica is in EMPTY status
I0729 07:07:11.394024 2566 replica.cpp:638] Replica in EMPTY status received a broadcasted recover request
I0729 07:07:11.394068 2566 recover.cpp:188] Received a recover response from a replica in EMPTY status
I0729 07:07:11.394145 2566 recover.cpp:542] Updating replica status to STARTING
2014-07-29 07:07:11,397:2508(0x2ace59f92700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:57594]
2014-07-29 07:07:11,401:2508(0x2ace90401700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:57594]
I0729 07:07:11.409651 2566 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 15.46787ms
I0729 07:07:11.409672 2566 replica.cpp:320] Persisted replica status to STARTING
I0729 07:07:11.409719 2566 recover.cpp:451] Replica is in STARTING status
I0729 07:07:11.409925 2566 replica.cpp:638] Replica in STARTING status received a broadcasted recover request
I0729 07:07:11.409962 2566 recover.cpp:188] Received a recover response from a replica in STARTING status
I0729 07:07:11.410028 2566 recover.cpp:542] Updating replica status to VOTING
I0729 07:07:11.445652 2566 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 35.592588ms
I0729 07:07:11.445673 2566 replica.cpp:320] Persisted replica status to VOTING
I0729 07:07:11.445703 2566 recover.cpp:556] Successfully joined the Paxos group
I0729 07:07:11.445744 2566 recover.cpp:440] Recover process terminated
I0729 07:07:11.445813 2566 log.cpp:656] Attempting to start the writer
I0729 07:07:11.446015 2566 replica.cpp:474] Replica received implicit promise request with proposal 1
2014-07-29 07:07:11,457:2508(0x2ace59f92700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:57594], sessionId=0x14780f1ba490000, negotiated timeout=6000
I0729 07:07:11.461655 2566 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 15.625294ms
I0729 07:07:11.461675 2566 replica.cpp:342] Persisted promised to 1
I0729 07:07:11.461854 2557 coordinator.cpp:230] Coordinator attemping to fill missing position
I0729 07:07:11.462095 2557 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2
I0729 07:07:11.462167 2566 group.cpp:313] Group process (group(56)@140.211.11.27:60355) connected to ZooKeeper
I0729 07:07:11.462182 2566 group.cpp:787] Syncing group operations: queue size (joins, cancels, datas) = (1, 0, 0)
I0729 07:07:11.462189 2566 group.cpp:385] Trying to create path '/log' in ZooKeeper
2014-07-29 07:07:11,465:2508(0x2ace90401700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:57594], sessionId=0x14780f1ba490001, negotiated timeout=6000
I0729 07:07:11.473757 2550 group.cpp:313] Group process (group(55)@140.211.11.27:60355) connected to ZooKeeper
I0729 07:07:11.473778 2550 group.cpp:787] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0)
I0729 07:07:11.473786 2550 group.cpp:385] Trying to create path '/log' in ZooKeeper
I0729 07:07:11.474051 2557 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 11.940849ms
I0729 07:07:11.474069 2557 replica.cpp:676] Persisted action at 0
I0729 07:07:11.474325 2562 replica.cpp:508] Replica received write request for position 0
I0729 07:07:11.474349 2562 leveldb.cpp:438] Reading position from leveldb took 11320ns
I0729 07:07:11.489652 2562 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 15.289151ms
I0729 07:07:11.489673 2562 replica.cpp:676] Persisted action at 0
I0729 07:07:11.489764 2562 replica.cpp:655] Replica received learned notice for position 0
I0729 07:07:11.502207 2562 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 12.429728ms
I0729 07:07:11.502229 2562 replica.cpp:676] Persisted action at 0
I0729 07:07:11.502238 2562 replica.cpp:661] Replica learned NOP action at position 0
I0729 07:07:11.502341 2562 log.cpp:672] Writer started with ending position 0
2014-07-29 07:07:11,545:2508(0x2ace90401700):ZOO_ERROR@handle_socket_error_msg@1721: Socket [127.0.0.1:57594] zk retcode=-4, errno=112(Host is down): failed while receiving a server response
2014-07-29 07:07:11,545:2508(0x2ace59f92700):ZOO_ERROR@handle_socket_error_msg@1721: Socket [127.0.0.1:57594] zk retcode=-4, errno=112(Host is down): failed while receiving a server response
I0729 07:07:11.553812 2550 group.cpp:418] Lost connection to ZooKeeper, attempting to reconnect ...
I0729 07:07:11.554090 2566 group.cpp:418] Lost connection to ZooKeeper, attempting to reconnect ...
I0729 07:07:11.573962 2508 zookeeper_test_server.cpp:122] Shutdown ZooKeeperTestServer on port 57594
I0729 07:07:11.574086 2551 log.cpp:680] Attempting to append 11 bytes to the log
I0729 07:07:11.574129 2551 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1
I0729 07:07:11.574267 2551 replica.cpp:508] Replica received write request for position 1
I0729 07:07:11.597652 2551 leveldb.cpp:343] Persisting action (27 bytes) to leveldb took 23.370542ms
I0729 07:07:11.597672 2551 replica.cpp:676] Persisted action at 1
I0729 07:07:11.597800 2551 replica.cpp:655] Replica received learned notice for position 1
2014-07-29 07:07:11,609:2508(0x2ace84402700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:41785] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I0729 07:07:11.613651 2551 leveldb.cpp:343] Persisting action (29 bytes) to leveldb took 15.839064ms
I0729 07:07:11.613672 2551 replica.cpp:676] Persisted action at 1
I0729 07:07:11.613679 2551 replica.cpp:661] Replica learned APPEND action at position 1
I0729 07:07:11.618790 2559 leveldb.cpp:438] Reading position from leveldb took 17696ns
2014-07-29 07:07:11,633:2508(0x2acbcdda5f80):ZOO_INFO@zookeeper_close@2522: Freeing zookeeper resources for sessionId=0x14780f1ba490000
2014-07-29 07:07:11,645:2508(0x2acbcdda5f80):ZOO_INFO@zookeeper_close@2522: Freeing zookeeper resources for sessionId=0x14780f1ba490001
[ OK ] LogZooKeeperTest.LostZooKeeper (348 ms)
[----------] 2 tests from LogZooKeeperTest (1194 ms total)
[----------] 2 tests from LogTest
[ RUN ] LogTest.Position
Using temporary directory '/tmp/LogTest_Position_P1zg6N'
I0729 07:07:11.708015 2508 leveldb.cpp:176] Opened db in 61.796441ms
I0729 07:07:11.735435 2508 leveldb.cpp:183] Compacted db in 27.394954ms
I0729 07:07:11.735458 2508 leveldb.cpp:198] Created db iterator in 3056ns
I0729 07:07:11.735466 2508 leveldb.cpp:204] Seeked to beginning of db in 602ns
I0729 07:07:11.735473 2508 leveldb.cpp:273] Iterated through 0 keys in the db in 211ns
I0729 07:07:11.735486 2508 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0729 07:07:11.769656 2563 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 23.960849ms
I0729 07:07:11.769680 2563 replica.cpp:320] Persisted replica status to VOTING
I0729 07:07:11.829758 2508 leveldb.cpp:176] Opened db in 55.996078ms
I0729 07:07:11.861649 2508 leveldb.cpp:183] Compacted db in 31.866809ms
I0729 07:07:11.861670 2508 leveldb.cpp:198] Created db iterator in 2164ns
I0729 07:07:11.861677 2508 leveldb.cpp:204] Seeked to beginning of db in 320ns
I0729 07:07:11.861685 2508 leveldb.cpp:273] Iterated through 0 keys in the db in 106ns
I0729 07:07:11.861695 2508 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0729 07:07:11.897653 2563 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 23.996676ms
I0729 07:07:11.897675 2563 replica.cpp:320] Persisted replica status to VOTING
I0729 07:07:11.953799 2508 leveldb.cpp:176] Opened db in 52.043185ms
I0729 07:07:12.004390 2508 leveldb.cpp:183] Compacted db in 50.565201ms
I0729 07:07:12.004429 2508 leveldb.cpp:198] Created db iterator in 14193ns
I0729 07:07:12.004447 2508 leveldb.cpp:204] Seeked to beginning of db in 7643ns
I0729 07:07:12.004462 2508 leveldb.cpp:273] Iterated through 1 keys in the db in 6344ns
I0729 07:07:12.004472 2508 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0729 07:07:12.045786 2508 leveldb.cpp:176] Opened db in 41.269465ms
I0729 07:07:12.097687 2508 leveldb.cpp:183] Compacted db in 51.874701ms
I0729 07:07:12.097796 2508 leveldb.cpp:198] Created db iterator in 4593ns
I0729 07:07:12.097880 2508 leveldb.cpp:204] Seeked to beginning of db in 8418ns
I0729 07:07:12.097973 2508 leveldb.cpp:273] Iterated through 1 keys in the db in 8563ns
I0729 07:07:12.098052 2508 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0729 07:07:12.101753 2563 recover.cpp:425] Starting replica recovery
I0729 07:07:12.101809 2563 recover.cpp:451] Replica is in VOTING status
I0729 07:07:12.101836 2563 recover.cpp:440] Recover process terminated
I0729 07:07:12.101896 2563 log.cpp:656] Attempting to start the writer
I0729 07:07:12.102145 2563 replica.cpp:474] Replica received implicit promise request with proposal 1
I0729 07:07:12.105655 2571 replica.cpp:474] Replica received implicit promise request with proposal 1
I0729 07:07:12.118355 2571 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 12.682795ms
I0729 07:07:12.118377 2571 replica.cpp:342] Persisted promised to 1
I0729 07:07:12.118456 2563 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 16.292346ms
I0729 07:07:12.118474 2563 replica.cpp:342] Persisted promised to 1
I0729 07:07:12.118582 2563 coordinator.cpp:230] Coordinator attemping to fill missing position
I0729 07:07:12.118839 2563 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2
I0729 07:07:12.119423 2571 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2
I0729 07:07:12.137650 2563 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 18.798172ms
I0729 07:07:12.137677 2563 replica.cpp:676] Persisted action at 0
I0729 07:07:12.137650 2571 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 18.213606ms
I0729 07:07:12.141664 2571 replica.cpp:676] Persisted action at 0
I0729 07:07:12.141863 2571 replica.cpp:508] Replica received write request for position 0
I0729 07:07:12.141890 2571 leveldb.cpp:438] Reading position from leveldb took 9342ns
I0729 07:07:12.145665 2572 replica.cpp:508] Replica received write request for position 0
I0729 07:07:12.145694 2572 leveldb.cpp:438] Reading position from leveldb took 13307ns
I0729 07:07:12.161653 2571 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 19.74974ms
I0729 07:07:12.161665 2572 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 15.952475ms
I0729 07:07:12.161690 2572 replica.cpp:676] Persisted action at 0
I0729 07:07:12.161676 2571 replica.cpp:676] Persisted action at 0
I0729 07:07:12.161865 2571 replica.cpp:655] Replica received learned notice for position 0
I0729 07:07:12.165664 2566 replica.cpp:655] Replica received learned notice for position 0
I0729 07:07:12.180131 2566 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 14.444967ms
I0729 07:07:12.180152 2566 replica.cpp:676] Persisted action at 0
I0729 07:07:12.180160 2566 replica.cpp:661] Replica learned NOP action at position 0
I0729 07:07:12.180269 2566 log.cpp:672] Writer started with ending position 0
I0729 07:07:12.181670 2570 log.cpp:680] Attempting to append 11 bytes to the log
I0729 07:07:12.181725 2570 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1
I0729 07:07:12.181915 2570 replica.cpp:508] Replica received write request for position 1
I0729 07:07:12.185662 2571 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 23.77661ms
I0729 07:07:12.185685 2571 replica.cpp:676] Persisted action at 0
I0729 07:07:12.185693 2571 replica.cpp:661] Replica learned NOP action at position 0
I0729 07:07:12.185706 2571 replica.cpp:508] Replica received write request for position 1
I0729 07:07:12.201655 2570 leveldb.cpp:343] Persisting action (27 bytes) to leveldb took 19.72526ms
I0729 07:07:12.201678 2570 replica.cpp:676] Persisted action at 1
I0729 07:07:12.206852 2571 leveldb.cpp:343] Persisting action (27 bytes) to leveldb took 21.135158ms
I0729 07:07:12.206873 2571 replica.cpp:676] Persisted action at 1
I0729 07:07:12.207022 2571 replica.cpp:655] Replica received learned notice for position 1
I0729 07:07:12.209682 2557 replica.cpp:655] Replica received learned notice for position 1
I0729 07:07:12.236018 2557 leveldb.cpp:343] Persisting action (29 bytes) to leveldb took 26.31864ms
I0729 07:07:12.236040 2557 replica.cpp:676] Persisted action at 1
I0729 07:07:12.236049 2557 replica.cpp:661] Replica learned APPEND action at position 1
I0729 07:07:12.241667 2571 leveldb.cpp:343] Persisting action (29 bytes) to leveldb took 34.620437ms
I0729 07:07:12.241689 2571 replica.cpp:676] Persisted action at 1
I0729 07:07:12.241698 2571 replica.cpp:661] Replica learned APPEND action at position 1
[ OK ] LogTest.Position (600 ms)
[ RUN ] LogTest.WriteRead
Using temporary directory '/tmp/LogTest_WriteRead_HxugY0'
I0729 07:07:12.293782 2508 leveldb.cpp:176] Opened db in 47.429204ms
I0729 07:07:12.305762 2508 leveldb.cpp:183] Compacted db in 11.949642ms
I0729 07:07:12.305788 2508 leveldb.cpp:198] Created db iterator in 3432ns
I0729 07:07:12.305799 2508 leveldb.cpp:204] Seeked to beginning of db in 549ns
I0729 07:07:12.305807 2508 leveldb.cpp:273] Iterated through 0 keys in the db in 218ns
I0729 07:07:12.305824 2508 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0729 07:07:12.337657 2573 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 24.001236ms
I0729 07:07:12.337683 2573 replica.cpp:320] Persisted replica status to VOTING
I0729 07:07:12.397819 2508 leveldb.cpp:176] Opened db in 57.934372ms
I0729 07:07:12.429664 2508 leveldb.cpp:183] Compacted db in 31.796364ms
I0729 07:07:12.429711 2508 leveldb.cpp:198] Created db iterator in 5007ns
I0729 07:07:12.429720 2508 leveldb.cpp:204] Seeked to beginning of db in 1066ns
I0729 07:07:12.429728 2508 leveldb.cpp:273] Iterated through 0 keys in the db in 239ns
I0729 07:07:12.429745 2508 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0729 07:07:12.454804 2573 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 21.520102ms
I0729 07:07:12.454829 2573 replica.cpp:320] Persisted replica status to VOTING
I0729 07:07:12.501808 2508 leveldb.cpp:176] Opened db in 46.804508ms
I0729 07:07:12.541800 2508 leveldb.cpp:183] Compacted db in 39.96206ms
I0729 07:07:12.541831 2508 leveldb.cpp:198] Created db iterator in 5503ns
I0729 07:07:12.541846 2508 leveldb.cpp:204] Seeked to beginning of db in 7246ns
I0729 07:07:12.541867 2508 leveldb.cpp:273] Iterated through 1 keys in the db in 11847ns
I0729 07:07:12.541880 2508 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0729 07:07:12.578094 2508 leveldb.cpp:176] Opened db in 36.147387ms
I0729 07:07:12.645654 2508 leveldb.cpp:183] Compacted db in 67.53159ms
I0729 07:07:12.645683 2508 leveldb.cpp:198] Created db iterator in 5820ns
I0729 07:07:12.645700 2508 leveldb.cpp:204] Seeked to beginning of db in 9689ns
I0729 07:07:12.645720 2508 leveldb.cpp:273] Iterated through 1 keys in the db in 11012ns
I0729 07:07:12.645733 2508 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0729 07:07:12.645908 2568 recover.cpp:425] Starting replica recovery
I0729 07:07:12.645982 2568 recover.cpp:451] Replica is in VOTING status
I0729 07:07:12.646020 2568 recover.cpp:440] Recover process terminated
I0729 07:07:12.646159 2573 log.cpp:656] Attempting to start the writer
I0729 07:07:12.646443 2573 replica.cpp:474] Replica received implicit promise request with proposal 1
I0729 07:07:12.646584 2567 replica.cpp:474] Replica received implicit promise request with proposal 1
I0729 07:07:12.665655 2567 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 19.056007ms
I0729 07:07:12.665683 2567 replica.cpp:342] Persisted promised to 1
I0729 07:07:12.665747 2573 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 19.288472ms
I0729 07:07:12.665762 2573 replica.cpp:342] Persisted promised to 1
I0729 07:07:12.665869 2573 coordinator.cpp:230] Coordinator attemping to fill missing position
I0729 07:07:12.666137 2573 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2
I0729 07:07:12.666203 2567 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2
I0729 07:07:12.681455 2567 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 15.236944ms
I0729 07:07:12.681481 2567 replica.cpp:676] Persisted action at 0
I0729 07:07:12.681659 2573 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 15.50424ms
I0729 07:07:12.681682 2573 replica.cpp:676] Persisted action at 0
I0729 07:07:12.681881 2561 replica.cpp:508] Replica received write request for position 0
I0729 07:07:12.681907 2561 leveldb.cpp:438] Reading position from leveldb took 12899ns
I0729 07:07:12.682023 2564 replica.cpp:508] Replica received write request for position 0
I0729 07:07:12.682044 2564 leveldb.cpp:438] Reading position from leveldb took 8564ns
I0729 07:07:12.695243 2561 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 13.322069ms
I0729 07:07:12.695266 2561 replica.cpp:676] Persisted action at 0
I0729 07:07:12.695328 2564 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 13.272095ms
I0729 07:07:12.695343 2564 replica.cpp:676] Persisted action at 0
I0729 07:07:12.695437 2564 replica.cpp:655] Replica received learned notice for position 0
I0729 07:07:12.695498 2561 replica.cpp:655] Replica received learned notice for position 0
I0729 07:07:12.713656 2561 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 18.143042ms
I0729 07:07:12.713680 2561 replica.cpp:676] Persisted action at 0
I0729 07:07:12.713688 2561 replica.cpp:661] Replica learned NOP action at position 0
I0729 07:07:12.713714 2564 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 18.263238ms
I0729 07:07:12.713734 2564 replica.cpp:676] Persisted action at 0
I0729 07:07:12.713742 2564 replica.cpp:661] Replica learned NOP action at position 0
I0729 07:07:12.713804 2561 log.cpp:672] Writer started with ending position 0
I0729 07:07:12.717730 2552 log.cpp:680] Attempting to append 11 bytes to the log
I0729 07:07:12.717810 2554 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1
I0729 07:07:12.718009 2554 replica.cpp:508] Replica received write request for position 1
I0729 07:07:12.718096 2565 replica.cpp:508] Replica received write request for position 1
I0729 07:07:12.727469 2554 leveldb.cpp:343] Persisting action (27 bytes) to leveldb took 9.444766ms
I0729 07:07:12.727493 2554 replica.cpp:676] Persisted action at 1
I0729 07:07:12.729652 2565 leveldb.cpp:343] Persisting action (27 bytes) to leveldb took 11.539557ms
I0729 07:07:12.729675 2565 replica.cpp:676] Persisted action at 1
I0729 07:07:12.729817 2571 replica.cpp:655] Replica received learned notice for position 1
I0729 07:07:12.729823 2565 replica.cpp:655] Replica received learned notice for position 1
I0729 07:07:12.739542 2571 leveldb.cpp:343] Persisting action (29 bytes) to leveldb took 9.702782ms
I0729 07:07:12.739565 2571 replica.cpp:676] Persisted action at 1
I0729 07:07:12.739574 2571 replica.cpp:661] Replica learned APPEND action at position 1
I0729 07:07:12.752599 2565 leveldb.cpp:343] Persisting action (29 bytes) to leveldb took 20.157634ms
I0729 07:07:12.752619 2565 replica.cpp:676] Persisted action at 1
I0729 07:07:12.752627 2565 replica.cpp:661] Replica learned APPEND action at position 1
I0729 07:07:12.757760 2553 leveldb.cpp:438] Reading position from leveldb took 12423ns
[ OK ] LogTest.WriteRead (516 ms)
[----------] 2 tests from LogTest (1116 ms total)
[----------] Global test environment tear-down
[==========] 390 tests from 64 test cases ran. (474014 ms total)
[ PASSED ] 389 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] SlaveRecoveryTest/0.SchedulerFailover, where TypeParam = mesos::internal::slave::MesosContainerizer
1 FAILED TEST
YOU HAVE 4 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/mesos-0.20.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/mesos-0.20.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/mesos-0.20.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/mesos-0.20.0/_build'
make: *** [distcheck] Error 1
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal :
Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME #2018
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/2018/changes>
Re: Build failed in Jenkins: Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME
#2017
Posted by Benjamin Mahler <be...@gmail.com>.
+yan
Can you take a look at this detector test when you have a moment?
On Tue, Jul 29, 2014 at 2:46 PM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:
> See <
> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/2017/changes
> >
>
> Changes:
>
> [yan] Fixed a bug that caused 'make dist' unable to patch leveldb.
>
> [bmahler] Fixed the master to accept a file:// based zk flag.
>
> ------------------------------------------
> [...truncated 60512 lines...]
> I0729 21:46:09.010236 18020 log.cpp:699] Attempting to truncate the log to
> 1
> I0729 21:46:09.010361 18020 master.cpp:987] Recovered 0 slaves from the
> Registry (100B) ; allowing 10mins for slaves to re-register
> I0729 21:46:09.010462 18020 coordinator.cpp:340] Coordinator attempting to
> write TRUNCATE action at position 2
> I0729 21:46:09.010741 18020 replica.cpp:508] Replica received write
> request for position 2
> I0729 21:46:09.033649 18020 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 22.836954ms
> I0729 21:46:09.033723 18020 replica.cpp:676] Persisted action at 2
> I0729 21:46:09.033946 18020 replica.cpp:655] Replica received learned
> notice for position 2
> I0729 21:46:09.052065 18020 leveldb.cpp:343] Persisting action (18 bytes)
> to leveldb took 18.048555ms
> I0729 21:46:09.052150 18020 leveldb.cpp:401] Deleting ~1 keys from leveldb
> took 15783ns
> I0729 21:46:09.052211 18020 replica.cpp:676] Persisted action at 2
> I0729 21:46:09.052274 18020 replica.cpp:661] Replica learned TRUNCATE
> action at position 2
> I0729 21:46:09.060420 17989 sched.cpp:139] Version: 0.20.0
> I0729 21:46:09.061787 18035 sched.cpp:235] New master detected at
> master@140.211.11.27:33282
> I0729 21:46:09.061806 18035 sched.cpp:285] Authenticating with master
> master@140.211.11.27:33282
> I0729 21:46:09.061887 18035 authenticatee.hpp:128] Creating new client
> SASL connection
> I0729 21:46:09.062000 18035 master.cpp:3504] Authenticating
> scheduler-1915e2c2-07df-4bf0-8217-157ba48640b1@140.211.11.27:33282
> I0729 21:46:09.062077 18035 authenticator.hpp:156] Creating new server
> SASL connection
> I0729 21:46:09.062155 18035 authenticatee.hpp:219] Received SASL
> authentication mechanisms: CRAM-MD5
> I0729 21:46:09.062170 18035 authenticatee.hpp:245] Attempting to
> authenticate with mechanism 'CRAM-MD5'
> I0729 21:46:09.062191 18035 authenticator.hpp:262] Received SASL
> authentication start
> I0729 21:46:09.062222 18035 authenticator.hpp:384] Authentication requires
> more steps
> I0729 21:46:09.062244 18035 authenticatee.hpp:265] Received SASL
> authentication step
> I0729 21:46:09.062273 18035 authenticator.hpp:290] Received SASL
> authentication step
> I0729 21:46:09.062284 18035 auxprop.cpp:81] Request to lookup properties
> for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0729 21:46:09.062291 18035 auxprop.cpp:153] Looking up auxiliary property
> '*userPassword'
> I0729 21:46:09.062299 18035 auxprop.cpp:153] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0729 21:46:09.062307 18035 auxprop.cpp:81] Request to lookup properties
> for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0729 21:46:09.062314 18035 auxprop.cpp:103] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0729 21:46:09.062319 18035 auxprop.cpp:103] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0729 21:46:09.062330 18035 authenticator.hpp:376] Authentication success
> I0729 21:46:09.062352 18035 authenticatee.hpp:305] Authentication success
> I0729 21:46:09.062371 18035 master.cpp:3544] Successfully authenticated
> principal 'test-principal' at
> scheduler-1915e2c2-07df-4bf0-8217-157ba48640b1@140.211.11.27:33282
> I0729 21:46:09.062429 18035 sched.cpp:359] Successfully authenticated with
> master master@140.211.11.27:33282
> I0729 21:46:09.062439 18035 sched.cpp:478] Sending registration request to
> master@140.211.11.27:33282
> I0729 21:46:09.062475 18035 master.cpp:1248] Received registration request
> from scheduler-1915e2c2-07df-4bf0-8217-157ba48640b1@140.211.11.27:33282
> I0729 21:46:09.062490 18035 master.cpp:1208] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0729 21:46:09.062582 18035 master.cpp:1307] Registering framework
> 20140729-214608-453759884-33282-17989-0000 at
> scheduler-1915e2c2-07df-4bf0-8217-157ba48640b1@140.211.11.27:33282
> I0729 21:46:09.062659 18035 sched.cpp:409] Framework registered with
> 20140729-214608-453759884-33282-17989-0000
> I0729 21:46:09.062680 18035 sched.cpp:423] Scheduler::registered took
> 11669ns
> I0729 21:46:09.062780 18035 hierarchical_allocator_process.hpp:331] Added
> framework 20140729-214608-453759884-33282-17989-0000
> I0729 21:46:09.062789 18035 hierarchical_allocator_process.hpp:724] No
> resources available to allocate!
> I0729 21:46:09.062794 18035 hierarchical_allocator_process.hpp:686]
> Performed allocation for 0 slaves in 5982ns
> I0729 21:46:09.066913 17989 sched.cpp:139] Version: 0.20.0
> I0729 21:46:09.073720 18030 sched.cpp:235] New master detected at
> master@140.211.11.27:33282
> I0729 21:46:09.073740 18030 sched.cpp:285] Authenticating with master
> master@140.211.11.27:33282
> I0729 21:46:09.073814 18030 authenticatee.hpp:128] Creating new client
> SASL connection
> I0729 21:46:09.073930 18030 master.cpp:3504] Authenticating
> scheduler-b04aeb01-5588-421e-b069-5efed3c3bb95@140.211.11.27:33282
> I0729 21:46:09.073998 18030 authenticator.hpp:156] Creating new server
> SASL connection
> I0729 21:46:09.074080 18030 authenticatee.hpp:219] Received SASL
> authentication mechanisms: CRAM-MD5
> I0729 21:46:09.074095 18030 authenticatee.hpp:245] Attempting to
> authenticate with mechanism 'CRAM-MD5'
> I0729 21:46:09.074117 18030 authenticator.hpp:262] Received SASL
> authentication start
> I0729 21:46:09.074151 18030 authenticator.hpp:384] Authentication requires
> more steps
> I0729 21:46:09.074175 18030 authenticatee.hpp:265] Received SASL
> authentication step
> I0729 21:46:09.074204 18030 authenticator.hpp:290] Received SASL
> authentication step
> I0729 21:46:09.074216 18030 auxprop.cpp:81] Request to lookup properties
> for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0729 21:46:09.074223 18030 auxprop.cpp:153] Looking up auxiliary property
> '*userPassword'
> I0729 21:46:09.074233 18030 auxprop.cpp:153] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0729 21:46:09.074240 18030 auxprop.cpp:81] Request to lookup properties
> for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0729 21:46:09.074246 18030 auxprop.cpp:103] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0729 21:46:09.074251 18030 auxprop.cpp:103] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0729 21:46:09.074262 18030 authenticator.hpp:376] Authentication success
> I0729 21:46:09.074285 18030 authenticatee.hpp:305] Authentication success
> I0729 21:46:09.074304 18030 master.cpp:3544] Successfully authenticated
> principal 'test-principal' at
> scheduler-b04aeb01-5588-421e-b069-5efed3c3bb95@140.211.11.27:33282
> I0729 21:46:09.074362 18030 sched.cpp:359] Successfully authenticated with
> master master@140.211.11.27:33282
> I0729 21:46:09.074373 18030 sched.cpp:478] Sending registration request to
> master@140.211.11.27:33282
> I0729 21:46:09.074410 18030 master.cpp:1248] Received registration request
> from scheduler-b04aeb01-5588-421e-b069-5efed3c3bb95@140.211.11.27:33282
> I0729 21:46:09.074425 18030 master.cpp:1208] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0729 21:46:09.074515 18030 master.cpp:1307] Registering framework
> 20140729-214608-453759884-33282-17989-0001 at
> scheduler-b04aeb01-5588-421e-b069-5efed3c3bb95@140.211.11.27:33282
> I0729 21:46:09.074573 18030 sched.cpp:409] Framework registered with
> 20140729-214608-453759884-33282-17989-0001
> I0729 21:46:09.074594 18030 sched.cpp:423] Scheduler::registered took
> 12679ns
> I0729 21:46:09.074656 18030 hierarchical_allocator_process.hpp:331] Added
> framework 20140729-214608-453759884-33282-17989-0001
> I0729 21:46:09.074663 18030 hierarchical_allocator_process.hpp:724] No
> resources available to allocate!
> I0729 21:46:09.074668 18030 hierarchical_allocator_process.hpp:686]
> Performed allocation for 0 slaves in 5776ns
> I0729 21:46:09.075280 17989 containerizer.cpp:124] Using isolation:
> posix/cpu,posix/mem
> I0729 21:46:09.077713 18012 slave.cpp:169] Slave started on 197)@
> 140.211.11.27:33282
> I0729 21:46:09.077735 18012 credentials.hpp:84] Loading credential for
> authentication from
> '/tmp/DRFAllocatorTest_SameShareAllocations_Hi8IXT/credential'
> I0729 21:46:09.077811 18012 slave.cpp:267] Slave using credential for:
> test-principal
> I0729 21:46:09.077913 18012 slave.cpp:280] Slave resources: cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0729 21:46:09.077960 18012 slave.cpp:325] Slave hostname:
> hemera.apache.org
> I0729 21:46:09.077971 18012 slave.cpp:326] Slave checkpoint: false
> I0729 21:46:09.078552 18012 state.cpp:33] Recovering state from
> '/tmp/DRFAllocatorTest_SameShareAllocations_Hi8IXT/meta'
> I0729 21:46:09.078637 18012 status_update_manager.cpp:193] Recovering
> status update manager
> I0729 21:46:09.078691 18012 containerizer.cpp:287] Recovering containerizer
> I0729 21:46:09.078930 18012 slave.cpp:3128] Finished recovery
> I0729 21:46:09.079103 18012 slave.cpp:601] New master detected at
> master@140.211.11.27:33282
> I0729 21:46:09.079123 18012 slave.cpp:677] Authenticating with master
> master@140.211.11.27:33282
> I0729 21:46:09.079156 18012 slave.cpp:650] Detecting new master
> I0729 21:46:09.079190 18012 status_update_manager.cpp:167] New master
> detected at master@140.211.11.27:33282
> I0729 21:46:09.079213 18012 authenticatee.hpp:128] Creating new client
> SASL connection
> I0729 21:46:09.079315 18012 master.cpp:3504] Authenticating slave(197)@
> 140.211.11.27:33282
> I0729 21:46:09.079382 18012 authenticator.hpp:156] Creating new server
> SASL connection
> I0729 21:46:09.079459 18012 authenticatee.hpp:219] Received SASL
> authentication mechanisms: CRAM-MD5
> I0729 21:46:09.079473 18012 authenticatee.hpp:245] Attempting to
> authenticate with mechanism 'CRAM-MD5'
> I0729 21:46:09.079494 18012 authenticator.hpp:262] Received SASL
> authentication start
> I0729 21:46:09.079526 18012 authenticator.hpp:384] Authentication requires
> more steps
> I0729 21:46:09.079550 18012 authenticatee.hpp:265] Received SASL
> authentication step
> I0729 21:46:09.079578 18012 authenticator.hpp:290] Received SASL
> authentication step
> I0729 21:46:09.079591 18012 auxprop.cpp:81] Request to lookup properties
> for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0729 21:46:09.079596 18012 auxprop.cpp:153] Looking up auxiliary property
> '*userPassword'
> I0729 21:46:09.079604 18012 auxprop.cpp:153] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0729 21:46:09.079613 18012 auxprop.cpp:81] Request to lookup properties
> for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0729 21:46:09.079619 18012 auxprop.cpp:103] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0729 21:46:09.079624 18012 auxprop.cpp:103] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0729 21:46:09.079634 18012 authenticator.hpp:376] Authentication success
> I0729 21:46:09.079658 18012 authenticatee.hpp:305] Authentication success
> I0729 21:46:09.079677 18012 master.cpp:3544] Successfully authenticated
> principal 'test-principal' at slave(197)@140.211.11.27:33282
> I0729 21:46:09.079865 18034 hierarchical_allocator_process.hpp:724] No
> resources available to allocate!
> I0729 21:46:09.079879 18034 hierarchical_allocator_process.hpp:686]
> Performed allocation for 0 slaves in 20068ns
> I0729 21:46:09.083784 18012 slave.cpp:734] Successfully authenticated with
> master master@140.211.11.27:33282
> I0729 21:46:09.083822 18012 slave.cpp:972] Will retry registration in
> 16.606358ms if necessary
> I0729 21:46:09.083878 18012 master.cpp:2762] Registering slave at
> slave(197)@140.211.11.27:33282 (hemera.apache.org) with id
> 20140729-214608-453759884-33282-17989-0
> I0729 21:46:09.083962 18012 slave.cpp:972] Will retry registration in
> 12.799785ms if necessary
> I0729 21:46:09.084022 18012 registrar.cpp:422] Attempting to update the
> 'registry'
> I0729 21:46:09.084154 18020 master.cpp:2750] Ignoring register slave
> message from slave(197)@140.211.11.27:33282 (hemera.apache.org) as
> admission is already in progress
> I0729 21:46:09.121817 18026 log.cpp:680] Attempting to append 332 bytes to
> the log
> I0729 21:46:09.121870 18026 coordinator.cpp:340] Coordinator attempting to
> write APPEND action at position 3
> I0729 21:46:09.122102 18026 replica.cpp:508] Replica received write
> request for position 3
> I0729 21:46:09.133656 18026 leveldb.cpp:343] Persisting action (351 bytes)
> to leveldb took 11.540021ms
> I0729 21:46:09.133678 18026 replica.cpp:676] Persisted action at 3
> I0729 21:46:09.133867 18026 replica.cpp:655] Replica received learned
> notice for position 3
> I0729 21:46:09.161656 18026 leveldb.cpp:343] Persisting action (353 bytes)
> to leveldb took 27.774834ms
> I0729 21:46:09.161677 18026 replica.cpp:676] Persisted action at 3
> I0729 21:46:09.161685 18026 replica.cpp:661] Replica learned APPEND action
> at position 3
> I0729 21:46:09.161991 18026 registrar.cpp:479] Successfully updated
> 'registry'
> I0729 21:46:09.162075 18026 log.cpp:699] Attempting to truncate the log to
> 3
> I0729 21:46:09.162125 18026 master.cpp:2802] Registered slave
> 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282
> (hemera.apache.org)
> I0729 21:46:09.162137 18026 master.cpp:3972] Adding slave
> 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282
> (hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024;
> ports(*):[31000-32000]
> I0729 21:46:09.162240 18026 coordinator.cpp:340] Coordinator attempting to
> write TRUNCATE action at position 4
> I0729 21:46:09.162302 18026 slave.cpp:768] Registered with master
> master@140.211.11.27:33282; given slave ID
> 20140729-214608-453759884-33282-17989-0
> I0729 21:46:09.162403 18026 slave.cpp:2325] Received ping from
> slave-observer(166)@140.211.11.27:33282
> I0729 21:46:09.162457 18026 hierarchical_allocator_process.hpp:444] Added
> slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org) with
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
> I0729 21:46:09.162509 18026 hierarchical_allocator_process.hpp:750]
> Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
> slave 20140729-214608-453759884-33282-17989-0 to framework
> 20140729-214608-453759884-33282-17989-0000
> I0729 21:46:09.162611 18026 hierarchical_allocator_process.hpp:706]
> Performed allocation for slave 20140729-214608-453759884-33282-17989-0 in
> 124178ns
> I0729 21:46:09.162688 18026 master.hpp:816] Adding offer
> 20140729-214608-453759884-33282-17989-0 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.162730 18026 master.cpp:3451] Sending 1 offers to framework
> 20140729-214608-453759884-33282-17989-0000
> I0729 21:46:09.162863 18026 sched.cpp:546] Scheduler::resourceOffers took
> 28225ns
> I0729 21:46:09.163007 18026 master.hpp:826] Removing offer
> 20140729-214608-453759884-33282-17989-0 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.163056 18026 master.cpp:2125] Processing reply for offers:
> [ 20140729-214608-453759884-33282-17989-0 ] on slave
> 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282
> (hemera.apache.org) for framework
> 20140729-214608-453759884-33282-17989-0000
> I0729 21:46:09.163264 18026 replica.cpp:508] Replica received write
> request for position 4
> I0729 21:46:09.165680 18030 hierarchical_allocator_process.hpp:546]
> Framework 20140729-214608-453759884-33282-17989-0000 left cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave
> 20140729-214608-453759884-33282-17989-0
> I0729 21:46:09.181658 18026 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 18.375941ms
> I0729 21:46:09.181684 18026 replica.cpp:676] Persisted action at 4
> I0729 21:46:09.181861 18026 replica.cpp:655] Replica received learned
> notice for position 4
> I0729 21:46:09.200984 18026 leveldb.cpp:343] Persisting action (18 bytes)
> to leveldb took 19.10788ms
> I0729 21:46:09.201022 18026 leveldb.cpp:401] Deleting ~2 keys from leveldb
> took 18270ns
> I0729 21:46:09.201032 18026 replica.cpp:676] Persisted action at 4
> I0729 21:46:09.201040 18026 replica.cpp:661] Replica learned TRUNCATE
> action at position 4
> I0729 21:46:09.213791 18017 hierarchical_allocator_process.hpp:750]
> Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
> slave 20140729-214608-453759884-33282-17989-0 to framework
> 20140729-214608-453759884-33282-17989-0001
> I0729 21:46:09.213912 18017 hierarchical_allocator_process.hpp:686]
> Performed allocation for 1 slaves in 156306ns
> I0729 21:46:09.213964 18017 master.hpp:816] Adding offer
> 20140729-214608-453759884-33282-17989-1 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.214007 18017 master.cpp:3451] Sending 1 offers to framework
> 20140729-214608-453759884-33282-17989-0001
> I0729 21:46:09.214112 18017 sched.cpp:546] Scheduler::resourceOffers took
> 28780ns
> I0729 21:46:09.214210 18017 master.hpp:826] Removing offer
> 20140729-214608-453759884-33282-17989-1 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.214258 18017 master.cpp:2125] Processing reply for offers:
> [ 20140729-214608-453759884-33282-17989-1 ] on slave
> 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282
> (hemera.apache.org) for framework
> 20140729-214608-453759884-33282-17989-0001
> I0729 21:46:09.214426 18017 hierarchical_allocator_process.hpp:546]
> Framework 20140729-214608-453759884-33282-17989-0001 left cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave
> 20140729-214608-453759884-33282-17989-0
> I0729 21:46:09.221777 18033 hierarchical_allocator_process.hpp:750]
> Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
> slave 20140729-214608-453759884-33282-17989-0 to framework
> 20140729-214608-453759884-33282-17989-0000
> I0729 21:46:09.221890 18033 hierarchical_allocator_process.hpp:686]
> Performed allocation for 1 slaves in 166951ns
> I0729 21:46:09.221938 18033 master.hpp:816] Adding offer
> 20140729-214608-453759884-33282-17989-2 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.221978 18033 master.cpp:3451] Sending 1 offers to framework
> 20140729-214608-453759884-33282-17989-0000
> I0729 21:46:09.222071 18033 sched.cpp:546] Scheduler::resourceOffers took
> 24103ns
> I0729 21:46:09.222162 18033 master.hpp:826] Removing offer
> 20140729-214608-453759884-33282-17989-2 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.222209 18033 master.cpp:2125] Processing reply for offers:
> [ 20140729-214608-453759884-33282-17989-2 ] on slave
> 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282
> (hemera.apache.org) for framework
> 20140729-214608-453759884-33282-17989-0000
> I0729 21:46:09.222368 18033 hierarchical_allocator_process.hpp:546]
> Framework 20140729-214608-453759884-33282-17989-0000 left cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave
> 20140729-214608-453759884-33282-17989-0
> I0729 21:46:09.237612 18033 hierarchical_allocator_process.hpp:750]
> Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
> slave 20140729-214608-453759884-33282-17989-0 to framework
> 20140729-214608-453759884-33282-17989-0001
> I0729 21:46:09.237725 18033 hierarchical_allocator_process.hpp:686]
> Performed allocation for 1 slaves in 135611ns
> I0729 21:46:09.237777 18033 master.hpp:816] Adding offer
> 20140729-214608-453759884-33282-17989-3 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.237817 18033 master.cpp:3451] Sending 1 offers to framework
> 20140729-214608-453759884-33282-17989-0001
> I0729 21:46:09.237907 18033 sched.cpp:546] Scheduler::resourceOffers took
> 23481ns
> I0729 21:46:09.237998 18033 master.hpp:826] Removing offer
> 20140729-214608-453759884-33282-17989-3 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.238044 18033 master.cpp:2125] Processing reply for offers:
> [ 20140729-214608-453759884-33282-17989-3 ] on slave
> 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282
> (hemera.apache.org) for framework
> 20140729-214608-453759884-33282-17989-0001
> I0729 21:46:09.238196 18033 hierarchical_allocator_process.hpp:546]
> Framework 20140729-214608-453759884-33282-17989-0001 left cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave
> 20140729-214608-453759884-33282-17989-0
> I0729 21:46:09.246237 18033 master.cpp:123] No whitelist given.
> Advertising offers for all slaves
> I0729 21:46:09.246337 18033 hierarchical_allocator_process.hpp:750]
> Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
> slave 20140729-214608-453759884-33282-17989-0 to framework
> 20140729-214608-453759884-33282-17989-0000
> I0729 21:46:09.246436 18033 hierarchical_allocator_process.hpp:686]
> Performed allocation for 1 slaves in 120940ns
> I0729 21:46:09.246481 18033 master.hpp:816] Adding offer
> 20140729-214608-453759884-33282-17989-4 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.246520 18033 master.cpp:3451] Sending 1 offers to framework
> 20140729-214608-453759884-33282-17989-0000
> I0729 21:46:09.246610 18033 sched.cpp:546] Scheduler::resourceOffers took
> 23368ns
> I0729 21:46:09.246701 18033 master.hpp:826] Removing offer
> 20140729-214608-453759884-33282-17989-4 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.246745 18033 master.cpp:2125] Processing reply for offers:
> [ 20140729-214608-453759884-33282-17989-4 ] on slave
> 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282
> (hemera.apache.org) for framework
> 20140729-214608-453759884-33282-17989-0000
> I0729 21:46:09.246899 18033 hierarchical_allocator_process.hpp:546]
> Framework 20140729-214608-453759884-33282-17989-0000 left cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave
> 20140729-214608-453759884-33282-17989-0
> I0729 21:46:09.258255 18033 hierarchical_allocator_process.hpp:750]
> Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
> slave 20140729-214608-453759884-33282-17989-0 to framework
> 20140729-214608-453759884-33282-17989-0001
> I0729 21:46:09.258358 18033 hierarchical_allocator_process.hpp:686]
> Performed allocation for 1 slaves in 125647ns
> I0729 21:46:09.258404 18033 master.hpp:816] Adding offer
> 20140729-214608-453759884-33282-17989-5 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.258442 18033 master.cpp:3451] Sending 1 offers to framework
> 20140729-214608-453759884-33282-17989-0001
> I0729 21:46:09.258533 18033 sched.cpp:546] Scheduler::resourceOffers took
> 23643ns
> I0729 21:46:09.258621 18033 master.hpp:826] Removing offer
> 20140729-214608-453759884-33282-17989-5 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.258667 18033 master.cpp:2125] Processing reply for offers:
> [ 20140729-214608-453759884-33282-17989-5 ] on slave
> 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282
> (hemera.apache.org) for framework
> 20140729-214608-453759884-33282-17989-0001
> I0729 21:46:09.258819 18033 hierarchical_allocator_process.hpp:546]
> Framework 20140729-214608-453759884-33282-17989-0001 left cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave
> 20140729-214608-453759884-33282-17989-0
> I0729 21:46:09.272397 18016 hierarchical_allocator_process.hpp:750]
> Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
> slave 20140729-214608-453759884-33282-17989-0 to framework
> 20140729-214608-453759884-33282-17989-0000
> I0729 21:46:09.272543 18016 hierarchical_allocator_process.hpp:686]
> Performed allocation for 1 slaves in 183400ns
> I0729 21:46:09.272603 18016 master.hpp:816] Adding offer
> 20140729-214608-453759884-33282-17989-6 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.272644 18016 master.cpp:3451] Sending 1 offers to framework
> 20140729-214608-453759884-33282-17989-0000
> I0729 21:46:09.272742 18016 sched.cpp:546] Scheduler::resourceOffers took
> 25308ns
> I0729 21:46:09.272837 18016 master.hpp:826] Removing offer
> 20140729-214608-453759884-33282-17989-6 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.272886 18016 master.cpp:2125] Processing reply for offers:
> [ 20140729-214608-453759884-33282-17989-6 ] on slave
> 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282
> (hemera.apache.org) for framework
> 20140729-214608-453759884-33282-17989-0000
> I0729 21:46:09.273046 18016 hierarchical_allocator_process.hpp:546]
> Framework 20140729-214608-453759884-33282-17989-0000 left cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave
> 20140729-214608-453759884-33282-17989-0
> I0729 21:46:09.282601 18017 hierarchical_allocator_process.hpp:750]
> Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
> slave 20140729-214608-453759884-33282-17989-0 to framework
> 20140729-214608-453759884-33282-17989-0001
> I0729 21:46:09.282711 18017 hierarchical_allocator_process.hpp:686]
> Performed allocation for 1 slaves in 136829ns
> I0729 21:46:09.282759 18017 master.hpp:816] Adding offer
> 20140729-214608-453759884-33282-17989-7 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.282800 18017 master.cpp:3451] Sending 1 offers to framework
> 20140729-214608-453759884-33282-17989-0001
> I0729 21:46:09.282891 18017 sched.cpp:546] Scheduler::resourceOffers took
> 23003ns
> I0729 21:46:09.282981 18017 master.hpp:826] Removing offer
> 20140729-214608-453759884-33282-17989-7 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.283028 18017 master.cpp:2125] Processing reply for offers:
> [ 20140729-214608-453759884-33282-17989-7 ] on slave
> 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282
> (hemera.apache.org) for framework
> 20140729-214608-453759884-33282-17989-0001
> I0729 21:46:09.283182 18017 hierarchical_allocator_process.hpp:546]
> Framework 20140729-214608-453759884-33282-17989-0001 left cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave
> 20140729-214608-453759884-33282-17989-0
> I0729 21:46:09.293746 18011 hierarchical_allocator_process.hpp:750]
> Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
> slave 20140729-214608-453759884-33282-17989-0 to framework
> 20140729-214608-453759884-33282-17989-0000
> I0729 21:46:09.293859 18011 hierarchical_allocator_process.hpp:686]
> Performed allocation for 1 slaves in 164408ns
> I0729 21:46:09.293908 18011 master.hpp:816] Adding offer
> 20140729-214608-453759884-33282-17989-8 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.293948 18011 master.cpp:3451] Sending 1 offers to framework
> 20140729-214608-453759884-33282-17989-0000
> I0729 21:46:09.294039 18011 sched.cpp:546] Scheduler::resourceOffers took
> 23414ns
> I0729 21:46:09.294131 18011 master.hpp:826] Removing offer
> 20140729-214608-453759884-33282-17989-8 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.294178 18011 master.cpp:2125] Processing reply for offers:
> [ 20140729-214608-453759884-33282-17989-8 ] on slave
> 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282
> (hemera.apache.org) for framework
> 20140729-214608-453759884-33282-17989-0000
> I0729 21:46:09.294328 18011 hierarchical_allocator_process.hpp:546]
> Framework 20140729-214608-453759884-33282-17989-0000 left cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave
> 20140729-214608-453759884-33282-17989-0
> I0729 21:46:09.306864 18011 master.cpp:123] No whitelist given.
> Advertising offers for all slaves
> I0729 21:46:09.306917 18011 hierarchical_allocator_process.hpp:750]
> Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
> slave 20140729-214608-453759884-33282-17989-0 to framework
> 20140729-214608-453759884-33282-17989-0001
> I0729 21:46:09.307018 18011 hierarchical_allocator_process.hpp:686]
> Performed allocation for 1 slaves in 121713ns
> I0729 21:46:09.307068 18011 master.hpp:816] Adding offer
> 20140729-214608-453759884-33282-17989-9 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.307108 18011 master.cpp:3451] Sending 1 offers to framework
> 20140729-214608-453759884-33282-17989-0001
> I0729 21:46:09.307199 18011 sched.cpp:546] Scheduler::resourceOffers took
> 23502ns
> I0729 21:46:09.307289 18011 master.hpp:826] Removing offer
> 20140729-214608-453759884-33282-17989-9 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
> I0729 21:46:09.307335 18011 master.cpp:2125] Processing reply for offers:
> [ 20140729-214608-453759884-33282-17989-9 ] on slave
> 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282
> (hemera.apache.org) for framework
> 20140729-214608-453759884-33282-17989-0001
> I0729 21:46:09.307485 18011 hierarchical_allocator_process.hpp:546]
> Framework 20140729-214608-453759884-33282-17989-0001 left cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave
> 20140729-214608-453759884-33282-17989-0
> I0729 21:46:09.317766 17989 master.cpp:626] Master terminating
> I0729 21:46:09.318917 18011 sched.cpp:747] Stopping framework
> '20140729-214608-453759884-33282-17989-0000'
> I0729 21:46:09.318961 18011 sched.cpp:747] Stopping framework
> '20140729-214608-453759884-33282-17989-0001'
> I0729 21:46:09.318989 18011 slave.cpp:2332] master@140.211.11.27:33282
> exited
> W0729 21:46:09.318999 18011 slave.cpp:2335] Master disconnected! Waiting
> for a new master to be elected
> I0729 21:46:09.320304 17989 slave.cpp:485] Slave terminating
> [ OK ] DRFAllocatorTest.SameShareAllocations (566 ms)
> [----------] 2 tests from DRFAllocatorTest (1360 ms total)
>
> [----------] Global test environment tear-down
> [==========] 390 tests from 64 test cases ran. (454194 ms total)
> [ PASSED ] 389 tests.
> [ FAILED ] 1 test, listed below:
> [ FAILED ] ZooKeeperTest.LeaderDetectorTimeoutHandling
>
> 1 FAILED TEST
> YOU HAVE 4 DISABLED TESTS
>
> make[4]: *** [check-local] Error 1
> make[4]: Leaving directory
> `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/mesos-0.20.0/_build/src'
> make[3]: *** [check-am] Error 2
> make[3]: Leaving directory
> `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/mesos-0.20.0/_build/src'
> make[2]: *** [check] Error 2
> make[2]: Leaving directory
> `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/mesos-0.20.0/_build/src'
> make[1]: *** [check-recursive] Error 1
> make[1]: Leaving directory
> `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/mesos-0.20.0/_build'
> make: *** [distcheck] Error 1
> Build step 'Execute shell' marked build as failure
>
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME #2017
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/2017/changes>
Changes:
[yan] Fixed a bug that caused 'make dist' unable to patch leveldb.
[bmahler] Fixed the master to accept a file:// based zk flag.
------------------------------------------
[...truncated 60512 lines...]
I0729 21:46:09.010236 18020 log.cpp:699] Attempting to truncate the log to 1
I0729 21:46:09.010361 18020 master.cpp:987] Recovered 0 slaves from the Registry (100B) ; allowing 10mins for slaves to re-register
I0729 21:46:09.010462 18020 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2
I0729 21:46:09.010741 18020 replica.cpp:508] Replica received write request for position 2
I0729 21:46:09.033649 18020 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 22.836954ms
I0729 21:46:09.033723 18020 replica.cpp:676] Persisted action at 2
I0729 21:46:09.033946 18020 replica.cpp:655] Replica received learned notice for position 2
I0729 21:46:09.052065 18020 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 18.048555ms
I0729 21:46:09.052150 18020 leveldb.cpp:401] Deleting ~1 keys from leveldb took 15783ns
I0729 21:46:09.052211 18020 replica.cpp:676] Persisted action at 2
I0729 21:46:09.052274 18020 replica.cpp:661] Replica learned TRUNCATE action at position 2
I0729 21:46:09.060420 17989 sched.cpp:139] Version: 0.20.0
I0729 21:46:09.061787 18035 sched.cpp:235] New master detected at master@140.211.11.27:33282
I0729 21:46:09.061806 18035 sched.cpp:285] Authenticating with master master@140.211.11.27:33282
I0729 21:46:09.061887 18035 authenticatee.hpp:128] Creating new client SASL connection
I0729 21:46:09.062000 18035 master.cpp:3504] Authenticating scheduler-1915e2c2-07df-4bf0-8217-157ba48640b1@140.211.11.27:33282
I0729 21:46:09.062077 18035 authenticator.hpp:156] Creating new server SASL connection
I0729 21:46:09.062155 18035 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0729 21:46:09.062170 18035 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0729 21:46:09.062191 18035 authenticator.hpp:262] Received SASL authentication start
I0729 21:46:09.062222 18035 authenticator.hpp:384] Authentication requires more steps
I0729 21:46:09.062244 18035 authenticatee.hpp:265] Received SASL authentication step
I0729 21:46:09.062273 18035 authenticator.hpp:290] Received SASL authentication step
I0729 21:46:09.062284 18035 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0729 21:46:09.062291 18035 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0729 21:46:09.062299 18035 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0729 21:46:09.062307 18035 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0729 21:46:09.062314 18035 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0729 21:46:09.062319 18035 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0729 21:46:09.062330 18035 authenticator.hpp:376] Authentication success
I0729 21:46:09.062352 18035 authenticatee.hpp:305] Authentication success
I0729 21:46:09.062371 18035 master.cpp:3544] Successfully authenticated principal 'test-principal' at scheduler-1915e2c2-07df-4bf0-8217-157ba48640b1@140.211.11.27:33282
I0729 21:46:09.062429 18035 sched.cpp:359] Successfully authenticated with master master@140.211.11.27:33282
I0729 21:46:09.062439 18035 sched.cpp:478] Sending registration request to master@140.211.11.27:33282
I0729 21:46:09.062475 18035 master.cpp:1248] Received registration request from scheduler-1915e2c2-07df-4bf0-8217-157ba48640b1@140.211.11.27:33282
I0729 21:46:09.062490 18035 master.cpp:1208] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0729 21:46:09.062582 18035 master.cpp:1307] Registering framework 20140729-214608-453759884-33282-17989-0000 at scheduler-1915e2c2-07df-4bf0-8217-157ba48640b1@140.211.11.27:33282
I0729 21:46:09.062659 18035 sched.cpp:409] Framework registered with 20140729-214608-453759884-33282-17989-0000
I0729 21:46:09.062680 18035 sched.cpp:423] Scheduler::registered took 11669ns
I0729 21:46:09.062780 18035 hierarchical_allocator_process.hpp:331] Added framework 20140729-214608-453759884-33282-17989-0000
I0729 21:46:09.062789 18035 hierarchical_allocator_process.hpp:724] No resources available to allocate!
I0729 21:46:09.062794 18035 hierarchical_allocator_process.hpp:686] Performed allocation for 0 slaves in 5982ns
I0729 21:46:09.066913 17989 sched.cpp:139] Version: 0.20.0
I0729 21:46:09.073720 18030 sched.cpp:235] New master detected at master@140.211.11.27:33282
I0729 21:46:09.073740 18030 sched.cpp:285] Authenticating with master master@140.211.11.27:33282
I0729 21:46:09.073814 18030 authenticatee.hpp:128] Creating new client SASL connection
I0729 21:46:09.073930 18030 master.cpp:3504] Authenticating scheduler-b04aeb01-5588-421e-b069-5efed3c3bb95@140.211.11.27:33282
I0729 21:46:09.073998 18030 authenticator.hpp:156] Creating new server SASL connection
I0729 21:46:09.074080 18030 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0729 21:46:09.074095 18030 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0729 21:46:09.074117 18030 authenticator.hpp:262] Received SASL authentication start
I0729 21:46:09.074151 18030 authenticator.hpp:384] Authentication requires more steps
I0729 21:46:09.074175 18030 authenticatee.hpp:265] Received SASL authentication step
I0729 21:46:09.074204 18030 authenticator.hpp:290] Received SASL authentication step
I0729 21:46:09.074216 18030 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0729 21:46:09.074223 18030 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0729 21:46:09.074233 18030 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0729 21:46:09.074240 18030 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0729 21:46:09.074246 18030 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0729 21:46:09.074251 18030 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0729 21:46:09.074262 18030 authenticator.hpp:376] Authentication success
I0729 21:46:09.074285 18030 authenticatee.hpp:305] Authentication success
I0729 21:46:09.074304 18030 master.cpp:3544] Successfully authenticated principal 'test-principal' at scheduler-b04aeb01-5588-421e-b069-5efed3c3bb95@140.211.11.27:33282
I0729 21:46:09.074362 18030 sched.cpp:359] Successfully authenticated with master master@140.211.11.27:33282
I0729 21:46:09.074373 18030 sched.cpp:478] Sending registration request to master@140.211.11.27:33282
I0729 21:46:09.074410 18030 master.cpp:1248] Received registration request from scheduler-b04aeb01-5588-421e-b069-5efed3c3bb95@140.211.11.27:33282
I0729 21:46:09.074425 18030 master.cpp:1208] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0729 21:46:09.074515 18030 master.cpp:1307] Registering framework 20140729-214608-453759884-33282-17989-0001 at scheduler-b04aeb01-5588-421e-b069-5efed3c3bb95@140.211.11.27:33282
I0729 21:46:09.074573 18030 sched.cpp:409] Framework registered with 20140729-214608-453759884-33282-17989-0001
I0729 21:46:09.074594 18030 sched.cpp:423] Scheduler::registered took 12679ns
I0729 21:46:09.074656 18030 hierarchical_allocator_process.hpp:331] Added framework 20140729-214608-453759884-33282-17989-0001
I0729 21:46:09.074663 18030 hierarchical_allocator_process.hpp:724] No resources available to allocate!
I0729 21:46:09.074668 18030 hierarchical_allocator_process.hpp:686] Performed allocation for 0 slaves in 5776ns
I0729 21:46:09.075280 17989 containerizer.cpp:124] Using isolation: posix/cpu,posix/mem
I0729 21:46:09.077713 18012 slave.cpp:169] Slave started on 197)@140.211.11.27:33282
I0729 21:46:09.077735 18012 credentials.hpp:84] Loading credential for authentication from '/tmp/DRFAllocatorTest_SameShareAllocations_Hi8IXT/credential'
I0729 21:46:09.077811 18012 slave.cpp:267] Slave using credential for: test-principal
I0729 21:46:09.077913 18012 slave.cpp:280] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0729 21:46:09.077960 18012 slave.cpp:325] Slave hostname: hemera.apache.org
I0729 21:46:09.077971 18012 slave.cpp:326] Slave checkpoint: false
I0729 21:46:09.078552 18012 state.cpp:33] Recovering state from '/tmp/DRFAllocatorTest_SameShareAllocations_Hi8IXT/meta'
I0729 21:46:09.078637 18012 status_update_manager.cpp:193] Recovering status update manager
I0729 21:46:09.078691 18012 containerizer.cpp:287] Recovering containerizer
I0729 21:46:09.078930 18012 slave.cpp:3128] Finished recovery
I0729 21:46:09.079103 18012 slave.cpp:601] New master detected at master@140.211.11.27:33282
I0729 21:46:09.079123 18012 slave.cpp:677] Authenticating with master master@140.211.11.27:33282
I0729 21:46:09.079156 18012 slave.cpp:650] Detecting new master
I0729 21:46:09.079190 18012 status_update_manager.cpp:167] New master detected at master@140.211.11.27:33282
I0729 21:46:09.079213 18012 authenticatee.hpp:128] Creating new client SASL connection
I0729 21:46:09.079315 18012 master.cpp:3504] Authenticating slave(197)@140.211.11.27:33282
I0729 21:46:09.079382 18012 authenticator.hpp:156] Creating new server SASL connection
I0729 21:46:09.079459 18012 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0729 21:46:09.079473 18012 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0729 21:46:09.079494 18012 authenticator.hpp:262] Received SASL authentication start
I0729 21:46:09.079526 18012 authenticator.hpp:384] Authentication requires more steps
I0729 21:46:09.079550 18012 authenticatee.hpp:265] Received SASL authentication step
I0729 21:46:09.079578 18012 authenticator.hpp:290] Received SASL authentication step
I0729 21:46:09.079591 18012 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0729 21:46:09.079596 18012 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0729 21:46:09.079604 18012 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0729 21:46:09.079613 18012 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0729 21:46:09.079619 18012 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0729 21:46:09.079624 18012 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0729 21:46:09.079634 18012 authenticator.hpp:376] Authentication success
I0729 21:46:09.079658 18012 authenticatee.hpp:305] Authentication success
I0729 21:46:09.079677 18012 master.cpp:3544] Successfully authenticated principal 'test-principal' at slave(197)@140.211.11.27:33282
I0729 21:46:09.079865 18034 hierarchical_allocator_process.hpp:724] No resources available to allocate!
I0729 21:46:09.079879 18034 hierarchical_allocator_process.hpp:686] Performed allocation for 0 slaves in 20068ns
I0729 21:46:09.083784 18012 slave.cpp:734] Successfully authenticated with master master@140.211.11.27:33282
I0729 21:46:09.083822 18012 slave.cpp:972] Will retry registration in 16.606358ms if necessary
I0729 21:46:09.083878 18012 master.cpp:2762] Registering slave at slave(197)@140.211.11.27:33282 (hemera.apache.org) with id 20140729-214608-453759884-33282-17989-0
I0729 21:46:09.083962 18012 slave.cpp:972] Will retry registration in 12.799785ms if necessary
I0729 21:46:09.084022 18012 registrar.cpp:422] Attempting to update the 'registry'
I0729 21:46:09.084154 18020 master.cpp:2750] Ignoring register slave message from slave(197)@140.211.11.27:33282 (hemera.apache.org) as admission is already in progress
I0729 21:46:09.121817 18026 log.cpp:680] Attempting to append 332 bytes to the log
I0729 21:46:09.121870 18026 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3
I0729 21:46:09.122102 18026 replica.cpp:508] Replica received write request for position 3
I0729 21:46:09.133656 18026 leveldb.cpp:343] Persisting action (351 bytes) to leveldb took 11.540021ms
I0729 21:46:09.133678 18026 replica.cpp:676] Persisted action at 3
I0729 21:46:09.133867 18026 replica.cpp:655] Replica received learned notice for position 3
I0729 21:46:09.161656 18026 leveldb.cpp:343] Persisting action (353 bytes) to leveldb took 27.774834ms
I0729 21:46:09.161677 18026 replica.cpp:676] Persisted action at 3
I0729 21:46:09.161685 18026 replica.cpp:661] Replica learned APPEND action at position 3
I0729 21:46:09.161991 18026 registrar.cpp:479] Successfully updated 'registry'
I0729 21:46:09.162075 18026 log.cpp:699] Attempting to truncate the log to 3
I0729 21:46:09.162125 18026 master.cpp:2802] Registered slave 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282 (hemera.apache.org)
I0729 21:46:09.162137 18026 master.cpp:3972] Adding slave 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282 (hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0729 21:46:09.162240 18026 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4
I0729 21:46:09.162302 18026 slave.cpp:768] Registered with master master@140.211.11.27:33282; given slave ID 20140729-214608-453759884-33282-17989-0
I0729 21:46:09.162403 18026 slave.cpp:2325] Received ping from slave-observer(166)@140.211.11.27:33282
I0729 21:46:09.162457 18026 hierarchical_allocator_process.hpp:444] Added slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
I0729 21:46:09.162509 18026 hierarchical_allocator_process.hpp:750] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 to framework 20140729-214608-453759884-33282-17989-0000
I0729 21:46:09.162611 18026 hierarchical_allocator_process.hpp:706] Performed allocation for slave 20140729-214608-453759884-33282-17989-0 in 124178ns
I0729 21:46:09.162688 18026 master.hpp:816] Adding offer 20140729-214608-453759884-33282-17989-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.162730 18026 master.cpp:3451] Sending 1 offers to framework 20140729-214608-453759884-33282-17989-0000
I0729 21:46:09.162863 18026 sched.cpp:546] Scheduler::resourceOffers took 28225ns
I0729 21:46:09.163007 18026 master.hpp:826] Removing offer 20140729-214608-453759884-33282-17989-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.163056 18026 master.cpp:2125] Processing reply for offers: [ 20140729-214608-453759884-33282-17989-0 ] on slave 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282 (hemera.apache.org) for framework 20140729-214608-453759884-33282-17989-0000
I0729 21:46:09.163264 18026 replica.cpp:508] Replica received write request for position 4
I0729 21:46:09.165680 18030 hierarchical_allocator_process.hpp:546] Framework 20140729-214608-453759884-33282-17989-0000 left cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave 20140729-214608-453759884-33282-17989-0
I0729 21:46:09.181658 18026 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 18.375941ms
I0729 21:46:09.181684 18026 replica.cpp:676] Persisted action at 4
I0729 21:46:09.181861 18026 replica.cpp:655] Replica received learned notice for position 4
I0729 21:46:09.200984 18026 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 19.10788ms
I0729 21:46:09.201022 18026 leveldb.cpp:401] Deleting ~2 keys from leveldb took 18270ns
I0729 21:46:09.201032 18026 replica.cpp:676] Persisted action at 4
I0729 21:46:09.201040 18026 replica.cpp:661] Replica learned TRUNCATE action at position 4
I0729 21:46:09.213791 18017 hierarchical_allocator_process.hpp:750] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 to framework 20140729-214608-453759884-33282-17989-0001
I0729 21:46:09.213912 18017 hierarchical_allocator_process.hpp:686] Performed allocation for 1 slaves in 156306ns
I0729 21:46:09.213964 18017 master.hpp:816] Adding offer 20140729-214608-453759884-33282-17989-1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.214007 18017 master.cpp:3451] Sending 1 offers to framework 20140729-214608-453759884-33282-17989-0001
I0729 21:46:09.214112 18017 sched.cpp:546] Scheduler::resourceOffers took 28780ns
I0729 21:46:09.214210 18017 master.hpp:826] Removing offer 20140729-214608-453759884-33282-17989-1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.214258 18017 master.cpp:2125] Processing reply for offers: [ 20140729-214608-453759884-33282-17989-1 ] on slave 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282 (hemera.apache.org) for framework 20140729-214608-453759884-33282-17989-0001
I0729 21:46:09.214426 18017 hierarchical_allocator_process.hpp:546] Framework 20140729-214608-453759884-33282-17989-0001 left cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave 20140729-214608-453759884-33282-17989-0
I0729 21:46:09.221777 18033 hierarchical_allocator_process.hpp:750] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 to framework 20140729-214608-453759884-33282-17989-0000
I0729 21:46:09.221890 18033 hierarchical_allocator_process.hpp:686] Performed allocation for 1 slaves in 166951ns
I0729 21:46:09.221938 18033 master.hpp:816] Adding offer 20140729-214608-453759884-33282-17989-2 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.221978 18033 master.cpp:3451] Sending 1 offers to framework 20140729-214608-453759884-33282-17989-0000
I0729 21:46:09.222071 18033 sched.cpp:546] Scheduler::resourceOffers took 24103ns
I0729 21:46:09.222162 18033 master.hpp:826] Removing offer 20140729-214608-453759884-33282-17989-2 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.222209 18033 master.cpp:2125] Processing reply for offers: [ 20140729-214608-453759884-33282-17989-2 ] on slave 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282 (hemera.apache.org) for framework 20140729-214608-453759884-33282-17989-0000
I0729 21:46:09.222368 18033 hierarchical_allocator_process.hpp:546] Framework 20140729-214608-453759884-33282-17989-0000 left cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave 20140729-214608-453759884-33282-17989-0
I0729 21:46:09.237612 18033 hierarchical_allocator_process.hpp:750] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 to framework 20140729-214608-453759884-33282-17989-0001
I0729 21:46:09.237725 18033 hierarchical_allocator_process.hpp:686] Performed allocation for 1 slaves in 135611ns
I0729 21:46:09.237777 18033 master.hpp:816] Adding offer 20140729-214608-453759884-33282-17989-3 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.237817 18033 master.cpp:3451] Sending 1 offers to framework 20140729-214608-453759884-33282-17989-0001
I0729 21:46:09.237907 18033 sched.cpp:546] Scheduler::resourceOffers took 23481ns
I0729 21:46:09.237998 18033 master.hpp:826] Removing offer 20140729-214608-453759884-33282-17989-3 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.238044 18033 master.cpp:2125] Processing reply for offers: [ 20140729-214608-453759884-33282-17989-3 ] on slave 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282 (hemera.apache.org) for framework 20140729-214608-453759884-33282-17989-0001
I0729 21:46:09.238196 18033 hierarchical_allocator_process.hpp:546] Framework 20140729-214608-453759884-33282-17989-0001 left cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave 20140729-214608-453759884-33282-17989-0
I0729 21:46:09.246237 18033 master.cpp:123] No whitelist given. Advertising offers for all slaves
I0729 21:46:09.246337 18033 hierarchical_allocator_process.hpp:750] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 to framework 20140729-214608-453759884-33282-17989-0000
I0729 21:46:09.246436 18033 hierarchical_allocator_process.hpp:686] Performed allocation for 1 slaves in 120940ns
I0729 21:46:09.246481 18033 master.hpp:816] Adding offer 20140729-214608-453759884-33282-17989-4 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.246520 18033 master.cpp:3451] Sending 1 offers to framework 20140729-214608-453759884-33282-17989-0000
I0729 21:46:09.246610 18033 sched.cpp:546] Scheduler::resourceOffers took 23368ns
I0729 21:46:09.246701 18033 master.hpp:826] Removing offer 20140729-214608-453759884-33282-17989-4 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.246745 18033 master.cpp:2125] Processing reply for offers: [ 20140729-214608-453759884-33282-17989-4 ] on slave 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282 (hemera.apache.org) for framework 20140729-214608-453759884-33282-17989-0000
I0729 21:46:09.246899 18033 hierarchical_allocator_process.hpp:546] Framework 20140729-214608-453759884-33282-17989-0000 left cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave 20140729-214608-453759884-33282-17989-0
I0729 21:46:09.258255 18033 hierarchical_allocator_process.hpp:750] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 to framework 20140729-214608-453759884-33282-17989-0001
I0729 21:46:09.258358 18033 hierarchical_allocator_process.hpp:686] Performed allocation for 1 slaves in 125647ns
I0729 21:46:09.258404 18033 master.hpp:816] Adding offer 20140729-214608-453759884-33282-17989-5 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.258442 18033 master.cpp:3451] Sending 1 offers to framework 20140729-214608-453759884-33282-17989-0001
I0729 21:46:09.258533 18033 sched.cpp:546] Scheduler::resourceOffers took 23643ns
I0729 21:46:09.258621 18033 master.hpp:826] Removing offer 20140729-214608-453759884-33282-17989-5 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.258667 18033 master.cpp:2125] Processing reply for offers: [ 20140729-214608-453759884-33282-17989-5 ] on slave 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282 (hemera.apache.org) for framework 20140729-214608-453759884-33282-17989-0001
I0729 21:46:09.258819 18033 hierarchical_allocator_process.hpp:546] Framework 20140729-214608-453759884-33282-17989-0001 left cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave 20140729-214608-453759884-33282-17989-0
I0729 21:46:09.272397 18016 hierarchical_allocator_process.hpp:750] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 to framework 20140729-214608-453759884-33282-17989-0000
I0729 21:46:09.272543 18016 hierarchical_allocator_process.hpp:686] Performed allocation for 1 slaves in 183400ns
I0729 21:46:09.272603 18016 master.hpp:816] Adding offer 20140729-214608-453759884-33282-17989-6 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.272644 18016 master.cpp:3451] Sending 1 offers to framework 20140729-214608-453759884-33282-17989-0000
I0729 21:46:09.272742 18016 sched.cpp:546] Scheduler::resourceOffers took 25308ns
I0729 21:46:09.272837 18016 master.hpp:826] Removing offer 20140729-214608-453759884-33282-17989-6 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.272886 18016 master.cpp:2125] Processing reply for offers: [ 20140729-214608-453759884-33282-17989-6 ] on slave 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282 (hemera.apache.org) for framework 20140729-214608-453759884-33282-17989-0000
I0729 21:46:09.273046 18016 hierarchical_allocator_process.hpp:546] Framework 20140729-214608-453759884-33282-17989-0000 left cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave 20140729-214608-453759884-33282-17989-0
I0729 21:46:09.282601 18017 hierarchical_allocator_process.hpp:750] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 to framework 20140729-214608-453759884-33282-17989-0001
I0729 21:46:09.282711 18017 hierarchical_allocator_process.hpp:686] Performed allocation for 1 slaves in 136829ns
I0729 21:46:09.282759 18017 master.hpp:816] Adding offer 20140729-214608-453759884-33282-17989-7 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.282800 18017 master.cpp:3451] Sending 1 offers to framework 20140729-214608-453759884-33282-17989-0001
I0729 21:46:09.282891 18017 sched.cpp:546] Scheduler::resourceOffers took 23003ns
I0729 21:46:09.282981 18017 master.hpp:826] Removing offer 20140729-214608-453759884-33282-17989-7 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.283028 18017 master.cpp:2125] Processing reply for offers: [ 20140729-214608-453759884-33282-17989-7 ] on slave 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282 (hemera.apache.org) for framework 20140729-214608-453759884-33282-17989-0001
I0729 21:46:09.283182 18017 hierarchical_allocator_process.hpp:546] Framework 20140729-214608-453759884-33282-17989-0001 left cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave 20140729-214608-453759884-33282-17989-0
I0729 21:46:09.293746 18011 hierarchical_allocator_process.hpp:750] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 to framework 20140729-214608-453759884-33282-17989-0000
I0729 21:46:09.293859 18011 hierarchical_allocator_process.hpp:686] Performed allocation for 1 slaves in 164408ns
I0729 21:46:09.293908 18011 master.hpp:816] Adding offer 20140729-214608-453759884-33282-17989-8 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.293948 18011 master.cpp:3451] Sending 1 offers to framework 20140729-214608-453759884-33282-17989-0000
I0729 21:46:09.294039 18011 sched.cpp:546] Scheduler::resourceOffers took 23414ns
I0729 21:46:09.294131 18011 master.hpp:826] Removing offer 20140729-214608-453759884-33282-17989-8 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.294178 18011 master.cpp:2125] Processing reply for offers: [ 20140729-214608-453759884-33282-17989-8 ] on slave 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282 (hemera.apache.org) for framework 20140729-214608-453759884-33282-17989-0000
I0729 21:46:09.294328 18011 hierarchical_allocator_process.hpp:546] Framework 20140729-214608-453759884-33282-17989-0000 left cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave 20140729-214608-453759884-33282-17989-0
I0729 21:46:09.306864 18011 master.cpp:123] No whitelist given. Advertising offers for all slaves
I0729 21:46:09.306917 18011 hierarchical_allocator_process.hpp:750] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 to framework 20140729-214608-453759884-33282-17989-0001
I0729 21:46:09.307018 18011 hierarchical_allocator_process.hpp:686] Performed allocation for 1 slaves in 121713ns
I0729 21:46:09.307068 18011 master.hpp:816] Adding offer 20140729-214608-453759884-33282-17989-9 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.307108 18011 master.cpp:3451] Sending 1 offers to framework 20140729-214608-453759884-33282-17989-0001
I0729 21:46:09.307199 18011 sched.cpp:546] Scheduler::resourceOffers took 23502ns
I0729 21:46:09.307289 18011 master.hpp:826] Removing offer 20140729-214608-453759884-33282-17989-9 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140729-214608-453759884-33282-17989-0 (hemera.apache.org)
I0729 21:46:09.307335 18011 master.cpp:2125] Processing reply for offers: [ 20140729-214608-453759884-33282-17989-9 ] on slave 20140729-214608-453759884-33282-17989-0 at slave(197)@140.211.11.27:33282 (hemera.apache.org) for framework 20140729-214608-453759884-33282-17989-0001
I0729 21:46:09.307485 18011 hierarchical_allocator_process.hpp:546] Framework 20140729-214608-453759884-33282-17989-0001 left cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] unused on slave 20140729-214608-453759884-33282-17989-0
I0729 21:46:09.317766 17989 master.cpp:626] Master terminating
I0729 21:46:09.318917 18011 sched.cpp:747] Stopping framework '20140729-214608-453759884-33282-17989-0000'
I0729 21:46:09.318961 18011 sched.cpp:747] Stopping framework '20140729-214608-453759884-33282-17989-0001'
I0729 21:46:09.318989 18011 slave.cpp:2332] master@140.211.11.27:33282 exited
W0729 21:46:09.318999 18011 slave.cpp:2335] Master disconnected! Waiting for a new master to be elected
I0729 21:46:09.320304 17989 slave.cpp:485] Slave terminating
[ OK ] DRFAllocatorTest.SameShareAllocations (566 ms)
[----------] 2 tests from DRFAllocatorTest (1360 ms total)
[----------] Global test environment tear-down
[==========] 390 tests from 64 test cases ran. (454194 ms total)
[ PASSED ] 389 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ZooKeeperTest.LeaderDetectorTimeoutHandling
1 FAILED TEST
YOU HAVE 4 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/mesos-0.20.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/mesos-0.20.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/mesos-0.20.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/mesos-0.20.0/_build'
make: *** [distcheck] Error 1
Build step 'Execute shell' marked build as failure