You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2015/12/08 22:13:37 UTC
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #1331
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1331/>
------------------------------------------
[...truncated 149982 lines...]
I1208 21:13:32.888731 31805 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_UcnUDi/slaves/4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-S0/frameworks/4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-0000/executors/default/runs/5042430f-2899-4d52-9124-7c8072b1f90c' for gc 6.99998971481481days in the future
I1208 21:13:32.888869 31806 slave.cpp:3947] Cleaning up framework 4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-0000
I1208 21:13:32.888994 31804 status_update_manager.cpp:282] Closing status update streams for framework 4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-0000
I1208 21:13:32.889000 31805 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_UcnUDi/slaves/4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-S0/frameworks/4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-0000/executors/default' for gc 6.99998971283556days in the future
I1208 21:13:32.889173 31804 status_update_manager.cpp:528] Cleaning up status update stream for task ce556009-8357-4b71-ae64-32efac0c6a76 of framework 4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-0000
I1208 21:13:32.889294 31805 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_UcnUDi/slaves/4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-S0/frameworks/4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-0000' for gc 6.99998971096days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (116 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I1208 21:13:32.900418 31775 leveldb.cpp:174] Opened db in 5.410505ms
I1208 21:13:32.901538 31775 leveldb.cpp:181] Compacted db in 1.036746ms
I1208 21:13:32.901629 31775 leveldb.cpp:196] Created db iterator in 25385ns
I1208 21:13:32.901646 31775 leveldb.cpp:202] Seeked to beginning of db in 2077ns
I1208 21:13:32.901657 31775 leveldb.cpp:271] Iterated through 0 keys in the db in 345ns
I1208 21:13:32.901715 31775 replica.cpp:778] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1208 21:13:32.902657 31796 recover.cpp:447] Starting replica recovery
I1208 21:13:32.903240 31795 recover.cpp:473] Replica is in EMPTY status
I1208 21:13:32.904693 31798 replica.cpp:674] Replica in EMPTY status received a broadcasted recover request from (11493)@172.17.0.1:51123
I1208 21:13:32.905571 31806 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1208 21:13:32.906330 31805 recover.cpp:564] Updating replica status to STARTING
I1208 21:13:32.907173 31803 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 656317ns
I1208 21:13:32.907210 31803 replica.cpp:321] Persisted replica status to STARTING
I1208 21:13:32.907413 31803 recover.cpp:473] Replica is in STARTING status
I1208 21:13:32.908320 31802 master.cpp:365] Master 82f3b2af-5808-46f2-ae60-6bae2d0029cf (f652123f5286) started on 172.17.0.1:51123
I1208 21:13:32.908345 31802 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/N8LyKl/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/N8LyKl/master" --zk_session_timeout="10secs"
I1208 21:13:32.908740 31802 master.cpp:414] Master allowing unauthenticated frameworks to register
I1208 21:13:32.908751 31802 master.cpp:417] Master only allowing authenticated slaves to register
I1208 21:13:32.908759 31802 credentials.hpp:35] Loading credentials for authentication from '/tmp/N8LyKl/credentials'
I1208 21:13:32.909150 31802 master.cpp:456] Using default 'crammd5' authenticator
I1208 21:13:32.909302 31802 master.cpp:493] Authorization enabled
I1208 21:13:32.909888 31803 hierarchical.cpp:163] Initialized hierarchical allocator process
I1208 21:13:32.909265 31805 replica.cpp:674] Replica in STARTING status received a broadcasted recover request from (11494)@172.17.0.1:51123
I1208 21:13:32.910156 31805 whitelist_watcher.cpp:77] No whitelist given
I1208 21:13:32.910637 31809 recover.cpp:193] Received a recover response from a replica in STARTING status
I1208 21:13:32.911507 31797 recover.cpp:564] Updating replica status to VOTING
I1208 21:13:32.912325 31797 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 480213ns
I1208 21:13:32.912413 31797 replica.cpp:321] Persisted replica status to VOTING
I1208 21:13:32.912626 31797 recover.cpp:578] Successfully joined the Paxos group
I1208 21:13:32.912986 31797 recover.cpp:462] Recover process terminated
I1208 21:13:32.912693 31802 master.cpp:1637] The newly elected leader is master@172.17.0.1:51123 with id 82f3b2af-5808-46f2-ae60-6bae2d0029cf
I1208 21:13:32.913291 31802 master.cpp:1650] Elected as the leading master!
I1208 21:13:32.913398 31802 master.cpp:1395] Recovering from registrar
I1208 21:13:32.913847 31802 registrar.cpp:307] Recovering registrar
I1208 21:13:32.914738 31802 log.cpp:659] Attempting to start the writer
I1208 21:13:32.917070 31801 replica.cpp:494] Replica received implicit promise request from (11495)@172.17.0.1:51123 with proposal 1
I1208 21:13:32.917593 31801 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 417636ns
I1208 21:13:32.917620 31801 replica.cpp:343] Persisted promised to 1
I1208 21:13:32.918617 31805 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1208 21:13:32.920080 31809 replica.cpp:389] Replica received explicit promise request from (11496)@172.17.0.1:51123 for position 0 with proposal 2
I1208 21:13:32.920460 31809 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 335179ns
I1208 21:13:32.920488 31809 replica.cpp:713] Persisted action at 0
I1208 21:13:32.921687 31808 replica.cpp:538] Replica received write request for position 0 from (11497)@172.17.0.1:51123
I1208 21:13:32.921805 31808 leveldb.cpp:436] Reading position from leveldb took 52002ns
I1208 21:13:32.922269 31808 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 405087ns
I1208 21:13:32.922297 31808 replica.cpp:713] Persisted action at 0
I1208 21:13:32.923353 31808 replica.cpp:692] Replica received learned notice for position 0 from @0.0.0.0:0
I1208 21:13:32.923733 31808 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 343111ns
I1208 21:13:32.923771 31808 replica.cpp:713] Persisted action at 0
I1208 21:13:32.923796 31808 replica.cpp:698] Replica learned NOP action at position 0
I1208 21:13:32.924515 31801 log.cpp:675] Writer started with ending position 0
I1208 21:13:32.925943 31800 leveldb.cpp:436] Reading position from leveldb took 46404ns
I1208 21:13:32.927253 31801 registrar.cpp:340] Successfully fetched the registry (0B) in 13.302016ms
I1208 21:13:32.927388 31801 registrar.cpp:439] Applied 1 operations in 34368ns; attempting to update the 'registry'
I1208 21:13:32.928573 31801 log.cpp:683] Attempting to append 170 bytes to the log
I1208 21:13:32.928776 31801 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1208 21:13:32.929868 31808 replica.cpp:538] Replica received write request for position 1 from (11498)@172.17.0.1:51123
I1208 21:13:32.930430 31808 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 514150ns
I1208 21:13:32.930460 31808 replica.cpp:713] Persisted action at 1
I1208 21:13:32.938609 31806 replica.cpp:692] Replica received learned notice for position 1 from @0.0.0.0:0
I1208 21:13:32.939223 31806 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 544975ns
I1208 21:13:32.939254 31806 replica.cpp:713] Persisted action at 1
I1208 21:13:32.939286 31806 replica.cpp:698] Replica learned APPEND action at position 1
I1208 21:13:32.940592 31800 registrar.cpp:484] Successfully updated the 'registry' in 13.131008ms
I1208 21:13:32.940768 31800 registrar.cpp:370] Successfully recovered registrar
I1208 21:13:32.940899 31806 log.cpp:702] Attempting to truncate the log to 1
I1208 21:13:32.941201 31807 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1208 21:13:32.941354 31800 master.cpp:1447] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I1208 21:13:32.941386 31805 hierarchical.cpp:181] Skipping recovery of hierarchical allocator: nothing to recover
I1208 21:13:32.942443 31804 replica.cpp:538] Replica received write request for position 2 from (11499)@172.17.0.1:51123
I1208 21:13:32.943066 31804 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 575750ns
I1208 21:13:32.943095 31804 replica.cpp:713] Persisted action at 2
I1208 21:13:32.944013 31806 replica.cpp:692] Replica received learned notice for position 2 from @0.0.0.0:0
I1208 21:13:32.944552 31806 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 487053ns
I1208 21:13:32.944629 31806 leveldb.cpp:399] Deleting ~1 keys from leveldb took 40536ns
I1208 21:13:32.944664 31806 replica.cpp:713] Persisted action at 2
I1208 21:13:32.944705 31806 replica.cpp:698] Replica learned TRUNCATE action at position 2
I1208 21:13:32.953706 31775 scheduler.cpp:154] Version: 0.27.0
I1208 21:13:32.954695 31803 scheduler.cpp:236] New master detected at master@172.17.0.1:51123
I1208 21:13:32.956135 31803 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.1:51123
I1208 21:13:32.958519 31808 process.cpp:3077] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1208 21:13:32.958598 31808 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:33377
I1208 21:13:32.958845 31808 master.cpp:1899] Received subscription request for HTTP framework 'default'
I1208 21:13:32.958930 31808 master.cpp:1676] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1208 21:13:32.959635 31808 master.cpp:1991] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1208 21:13:32.960489 31796 master.hpp:1583] Sending heartbeat to 82f3b2af-5808-46f2-ae60-6bae2d0029cf-0000
I1208 21:13:32.961225 31799 hierarchical.cpp:267] Added framework 82f3b2af-5808-46f2-ae60-6bae2d0029cf-0000
I1208 21:13:32.961282 31796 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.1:51123
I1208 21:13:32.961302 31799 hierarchical.cpp:1317] No resources available to allocate!
I1208 21:13:32.961462 31799 hierarchical.cpp:1410] No inverse offers to send out!
I1208 21:13:32.961500 31799 hierarchical.cpp:1063] Performed allocation for 0 slaves in 245986ns
I1208 21:13:32.962980 31800 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.1:51123
I1208 21:13:32.963606 31800 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.1:51123
I1208 21:13:32.964252 31800 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I1208 21:13:32.964716 31799 process.cpp:3077] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1208 21:13:32.964787 31799 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:33378
I1208 21:13:32.964893 31799 master.cpp:2646] Processing REQUEST call for framework 82f3b2af-5808-46f2-ae60-6bae2d0029cf-0000 (default)
I1208 21:13:32.965018 31807 hierarchical.cpp:562] Received resource request from framework 82f3b2af-5808-46f2-ae60-6bae2d0029cf-0000
I1208 21:13:32.965303 31806 master.cpp:938] Master terminating
I1208 21:13:32.965538 31803 hierarchical.cpp:308] Removed framework 82f3b2af-5808-46f2-ae60-6bae2d0029cf-0000
E1208 21:13:32.968647 31806 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (78 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I1208 21:13:32.975648 31775 leveldb.cpp:174] Opened db in 2.24527ms
I1208 21:13:32.976327 31775 leveldb.cpp:181] Compacted db in 639122ns
I1208 21:13:32.976372 31775 leveldb.cpp:196] Created db iterator in 18080ns
I1208 21:13:32.976389 31775 leveldb.cpp:202] Seeked to beginning of db in 1676ns
I1208 21:13:32.976400 31775 leveldb.cpp:271] Iterated through 0 keys in the db in 222ns
I1208 21:13:32.976446 31775 replica.cpp:778] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1208 21:13:32.977051 31803 recover.cpp:447] Starting replica recovery
I1208 21:13:32.977452 31803 recover.cpp:473] Replica is in EMPTY status
I1208 21:13:32.979074 31804 replica.cpp:674] Replica in EMPTY status received a broadcasted recover request from (11504)@172.17.0.1:51123
I1208 21:13:32.979714 31801 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1208 21:13:32.981096 31800 recover.cpp:564] Updating replica status to STARTING
I1208 21:13:32.981772 31800 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 495034ns
I1208 21:13:32.981981 31800 replica.cpp:321] Persisted replica status to STARTING
I1208 21:13:32.983151 31798 recover.cpp:473] Replica is in STARTING status
I1208 21:13:32.983314 31795 master.cpp:365] Master f8764117-369a-4071-b13e-17a51f6f7ffd (f652123f5286) started on 172.17.0.1:51123
I1208 21:13:32.983537 31795 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/wpyUKH/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/wpyUKH/master" --zk_session_timeout="10secs"
I1208 21:13:32.984084 31795 master.cpp:414] Master allowing unauthenticated frameworks to register
I1208 21:13:32.984112 31795 master.cpp:417] Master only allowing authenticated slaves to register
I1208 21:13:32.984122 31795 credentials.hpp:35] Loading credentials for authentication from '/tmp/wpyUKH/credentials'
I1208 21:13:32.984542 31795 master.cpp:456] Using default 'crammd5' authenticator
I1208 21:13:32.986073 31798 replica.cpp:674] Replica in STARTING status received a broadcasted recover request from (11505)@172.17.0.1:51123
I1208 21:13:32.986407 31795 master.cpp:493] Authorization enabled
I1208 21:13:32.986498 31803 recover.cpp:193] Received a recover response from a replica in STARTING status
I1208 21:13:32.986698 31808 whitelist_watcher.cpp:77] No whitelist given
I1208 21:13:32.986721 31798 hierarchical.cpp:163] Initialized hierarchical allocator process
I1208 21:13:32.987228 31803 recover.cpp:564] Updating replica status to VOTING
I1208 21:13:32.987905 31805 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 521694ns
I1208 21:13:32.987937 31805 replica.cpp:321] Persisted replica status to VOTING
I1208 21:13:32.988183 31803 recover.cpp:578] Successfully joined the Paxos group
I1208 21:13:32.988435 31803 recover.cpp:462] Recover process terminated
I1208 21:13:32.989279 31796 master.cpp:1637] The newly elected leader is master@172.17.0.1:51123 with id f8764117-369a-4071-b13e-17a51f6f7ffd
I1208 21:13:32.989311 31796 master.cpp:1650] Elected as the leading master!
I1208 21:13:32.989330 31796 master.cpp:1395] Recovering from registrar
I1208 21:13:32.989565 31796 registrar.cpp:307] Recovering registrar
I1208 21:13:32.990625 31807 log.cpp:659] Attempting to start the writer
I1208 21:13:32.993171 31795 replica.cpp:494] Replica received implicit promise request from (11506)@172.17.0.1:51123 with proposal 1
I1208 21:13:32.993702 31795 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 403968ns
I1208 21:13:32.993783 31795 replica.cpp:343] Persisted promised to 1
I1208 21:13:32.994575 31804 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1208 21:13:32.996242 31807 replica.cpp:389] Replica received explicit promise request from (11507)@172.17.0.1:51123 for position 0 with proposal 2
I1208 21:13:32.996676 31807 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 388675ns
I1208 21:13:32.996702 31807 replica.cpp:713] Persisted action at 0
I1208 21:13:32.997856 31801 replica.cpp:538] Replica received write request for position 0 from (11508)@172.17.0.1:51123
I1208 21:13:32.998216 31801 leveldb.cpp:436] Reading position from leveldb took 33223ns
I1208 21:13:32.998778 31801 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 315548ns
I1208 21:13:32.998991 31801 replica.cpp:713] Persisted action at 0
I1208 21:13:32.999815 31801 replica.cpp:692] Replica received learned notice for position 0 from @0.0.0.0:0
I1208 21:13:33.000452 31801 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 605452ns
I1208 21:13:33.000479 31801 replica.cpp:713] Persisted action at 0
I1208 21:13:33.000499 31801 replica.cpp:698] Replica learned NOP action at position 0
I1208 21:13:33.001260 31796 log.cpp:675] Writer started with ending position 0
I1208 21:13:33.002645 31806 leveldb.cpp:436] Reading position from leveldb took 61218ns
I1208 21:13:33.003988 31794 registrar.cpp:340] Successfully fetched the registry (0B) in 14.37312ms
I1208 21:13:33.004207 31794 registrar.cpp:439] Applied 1 operations in 33883ns; attempting to update the 'registry'
I1208 21:13:33.005064 31800 log.cpp:683] Attempting to append 170 bytes to the log
I1208 21:13:33.005188 31809 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1208 21:13:33.006063 31798 replica.cpp:538] Replica received write request for position 1 from (11509)@172.17.0.1:51123
I1208 21:13:33.006561 31798 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 454382ns
I1208 21:13:33.006587 31798 replica.cpp:713] Persisted action at 1
I1208 21:13:33.007567 31800 replica.cpp:692] Replica received learned notice for position 1 from @0.0.0.0:0
I1208 21:13:33.008075 31800 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 451345ns
I1208 21:13:33.008112 31800 replica.cpp:713] Persisted action at 1
I1208 21:13:33.008147 31800 replica.cpp:698] Replica learned APPEND action at position 1
I1208 21:13:33.010313 31806 registrar.cpp:484] Successfully updated the 'registry' in 6.008064ms
I1208 21:13:33.010702 31806 registrar.cpp:370] Successfully recovered registrar
I1208 21:13:33.011247 31805 log.cpp:702] Attempting to truncate the log to 1
I1208 21:13:33.012493 31803 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1208 21:13:33.012821 31797 master.cpp:1447] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I1208 21:13:33.012935 31797 hierarchical.cpp:181] Skipping recovery of hierarchical allocator: nothing to recover
I1208 21:13:33.013968 31807 replica.cpp:538] Replica received write request for position 2 from (11510)@172.17.0.1:51123
I1208 21:13:33.014521 31807 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 478545ns
I1208 21:13:33.014552 31807 replica.cpp:713] Persisted action at 2
I1208 21:13:33.015481 31807 replica.cpp:692] Replica received learned notice for position 2 from @0.0.0.0:0
I1208 21:13:33.015897 31807 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 308611ns
I1208 21:13:33.016042 31807 leveldb.cpp:399] Deleting ~1 keys from leveldb took 47319ns
I1208 21:13:33.016083 31807 replica.cpp:713] Persisted action at 2
I1208 21:13:33.016109 31807 replica.cpp:698] Replica learned TRUNCATE action at position 2
I1208 21:13:33.023864 31775 scheduler.cpp:154] Version: 0.27.0
I1208 21:13:33.024884 31803 scheduler.cpp:236] New master detected at master@172.17.0.1:51123
I1208 21:13:33.026504 31806 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.1:51123
I1208 21:13:33.029641 31799 process.cpp:3077] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1208 21:13:33.029713 31799 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:33379
I1208 21:13:33.030135 31799 master.cpp:1899] Received subscription request for HTTP framework 'default'
I1208 21:13:33.030220 31799 master.cpp:1676] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1208 21:13:33.030812 31802 master.cpp:1991] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1208 21:13:33.032304 31796 hierarchical.cpp:267] Added framework f8764117-369a-4071-b13e-17a51f6f7ffd-0000
I1208 21:13:33.032318 31802 master.hpp:1583] Sending heartbeat to f8764117-369a-4071-b13e-17a51f6f7ffd-0000
I1208 21:13:33.032384 31796 hierarchical.cpp:1317] No resources available to allocate!
I1208 21:13:33.032418 31796 hierarchical.cpp:1410] No inverse offers to send out!
I1208 21:13:33.032444 31796 hierarchical.cpp:1063] Performed allocation for 0 slaves in 114998ns
I1208 21:13:33.033583 31799 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.1:51123
I1208 21:13:33.033951 31799 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.1:51123
I1208 21:13:33.034461 31806 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I1208 21:13:33.035090 31801 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.1:51123
I1208 21:13:33.037539 31807 process.cpp:3077] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1208 21:13:33.037637 31807 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:33380
I1208 21:13:33.037961 31807 master.cpp:2646] Processing REQUEST call for framework f8764117-369a-4071-b13e-17a51f6f7ffd-0000 (default)
I1208 21:13:33.038218 31805 hierarchical.cpp:562] Received resource request from framework f8764117-369a-4071-b13e-17a51f6f7ffd-0000
I1208 21:13:33.038645 31805 master.cpp:938] Master terminating
I1208 21:13:33.038851 31809 hierarchical.cpp:308] Removed framework f8764117-369a-4071-b13e-17a51f6f7ffd-0000
E1208 21:13:33.040077 31805 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (73 ms)
[----------] 22 tests from ContentType/SchedulerTest (4531 ms total)
[----------] Global test environment tear-down
[==========] 886 tests from 116 test cases ran. (367515 ms total)
[ PASSED ] 885 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] HealthTest.ObserveEndpoint
1 FAILED TEST
YOU HAVE 7 DISABLED TESTS
make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[4]: *** [check-local] Error 1
make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[3]: *** [check-am] Error 2
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1449606905-25998
Untagged: mesos-1449606905-25998:latest
Deleted: fdff04de0f52f84893cf5b01b069d65acd64d4feb6d5e1a02ef92f0c9eef4be4
Deleted: cd33e351a3abec2b2690c0de755c255c8bb347e3e1ea6a05c14c2e92bfef35dc
Deleted: f6092593961087fef619cfbbcb9a36b758e9875e6af3c92720c322897c02eeea
Deleted: 6de705835c0a9ad1ba9da6d73ae441e92759b069b218b410ea1d925c5ca8c688
Deleted: c2df9525e3dbfa57ca33d1cd2085bedded75a0b70bc6a1d532a1d7aed0dd9d2c
Deleted: 7d4cb399e41136eb94d74b2f52dbcdff8524a19ea47989ab54cb6112020fac14
Deleted: f31ffac0badc2531939e1464bb7aa793582b49de3ac6892ce51ad2c871e8638f
Deleted: 08c83f598fd5ad801bc21567afe9c48d9b32baae044988259e34bf374c67fd52
Deleted: 78041b6f0444fb0b4e429c6d822d766fa1d85beb868517da161e611a3b5e8ee8
Deleted: 2d9b6f9c813df223123fd206292b29d1409958dd6f1ee5c8519caad249994202
Deleted: c4b8076d485aa9f7ab196ff5324c8c91368224e82ef95d4b9f4e083f164e295a
Deleted: dffbe3fcd0e915faaaead626d8468e17e8a34f9486addda69601df7476e275bd
Deleted: 2b024206eeb74c6853b44d003aa189ca010fe08856e83fad57b4ec0024b8f770
Build step 'Execute shell' marked build as failure
Re: Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #1331
Posted by Benjamin Mahler <be...@gmail.com>.
Thanks! We should remove the "health" code related to this, was never
finished or used.
On Tue, Dec 8, 2015 at 1:19 PM, Neil Conway <ne...@gmail.com> wrote:
> This build failure is due to a broken test
> (HealthTest.ObserveEndpoint), and has already been fixed in master:
>
> https://reviews.apache.org/r/41100/
>
> Neil
>
> On Tue, Dec 8, 2015 at 1:13 PM, Apache Jenkins Server
> <je...@builds.apache.org> wrote:
> > See <
> https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1331/
> >
> >
> > ------------------------------------------
> > [...truncated 149982 lines...]
> > I1208 21:13:32.888731 31805 gc.cpp:54] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_UcnUDi/slaves/4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-S0/frameworks/4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-0000/executors/default/runs/5042430f-2899-4d52-9124-7c8072b1f90c'
> for gc 6.99998971481481days in the future
> > I1208 21:13:32.888869 31806 slave.cpp:3947] Cleaning up framework
> 4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-0000
> > I1208 21:13:32.888994 31804 status_update_manager.cpp:282] Closing
> status update streams for framework
> 4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-0000
> > I1208 21:13:32.889000 31805 gc.cpp:54] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_UcnUDi/slaves/4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-S0/frameworks/4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-0000/executors/default'
> for gc 6.99998971283556days in the future
> > I1208 21:13:32.889173 31804 status_update_manager.cpp:528] Cleaning up
> status update stream for task ce556009-8357-4b71-ae64-32efac0c6a76 of
> framework 4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-0000
> > I1208 21:13:32.889294 31805 gc.cpp:54] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_UcnUDi/slaves/4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-S0/frameworks/4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-0000'
> for gc 6.99998971096days in the future
> > [ OK ] ContentType/SchedulerTest.Message/1 (116 ms)
> > [ RUN ] ContentType/SchedulerTest.Request/0
> > I1208 21:13:32.900418 31775 leveldb.cpp:174] Opened db in 5.410505ms
> > I1208 21:13:32.901538 31775 leveldb.cpp:181] Compacted db in 1.036746ms
> > I1208 21:13:32.901629 31775 leveldb.cpp:196] Created db iterator in
> 25385ns
> > I1208 21:13:32.901646 31775 leveldb.cpp:202] Seeked to beginning of db
> in 2077ns
> > I1208 21:13:32.901657 31775 leveldb.cpp:271] Iterated through 0 keys in
> the db in 345ns
> > I1208 21:13:32.901715 31775 replica.cpp:778] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> > I1208 21:13:32.902657 31796 recover.cpp:447] Starting replica recovery
> > I1208 21:13:32.903240 31795 recover.cpp:473] Replica is in EMPTY status
> > I1208 21:13:32.904693 31798 replica.cpp:674] Replica in EMPTY status
> received a broadcasted recover request from (11493)@172.17.0.1:51123
> > I1208 21:13:32.905571 31806 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> > I1208 21:13:32.906330 31805 recover.cpp:564] Updating replica status to
> STARTING
> > I1208 21:13:32.907173 31803 leveldb.cpp:304] Persisting metadata (8
> bytes) to leveldb took 656317ns
> > I1208 21:13:32.907210 31803 replica.cpp:321] Persisted replica status to
> STARTING
> > I1208 21:13:32.907413 31803 recover.cpp:473] Replica is in STARTING
> status
> > I1208 21:13:32.908320 31802 master.cpp:365] Master
> 82f3b2af-5808-46f2-ae60-6bae2d0029cf (f652123f5286) started on
> 172.17.0.1:51123
> > I1208 21:13:32.908345 31802 master.cpp:367] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_slaves="true"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/N8LyKl/credentials" --framework_sorter="drf"
> --help="false" --hostname_lookup="true" --initialize_driver_logging="true"
> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> --max_slave_ping_timeouts="5" --quiet="false"
> --recovery_slave_removal_limit="100%" --registry="replicated_log"
> --registry_fetch_timeout="1mins" --registry_store_timeout="25secs"
> --registry_strict="true" --root_submissions="true"
> --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins"
> --user_sorter="drf" --version="false"
> --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui"
> --work_dir="/tmp/N8LyKl/master" --zk_session_timeout="10secs"
> > I1208 21:13:32.908740 31802 master.cpp:414] Master allowing
> unauthenticated frameworks to register
> > I1208 21:13:32.908751 31802 master.cpp:417] Master only allowing
> authenticated slaves to register
> > I1208 21:13:32.908759 31802 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/N8LyKl/credentials'
> > I1208 21:13:32.909150 31802 master.cpp:456] Using default 'crammd5'
> authenticator
> > I1208 21:13:32.909302 31802 master.cpp:493] Authorization enabled
> > I1208 21:13:32.909888 31803 hierarchical.cpp:163] Initialized
> hierarchical allocator process
> > I1208 21:13:32.909265 31805 replica.cpp:674] Replica in STARTING status
> received a broadcasted recover request from (11494)@172.17.0.1:51123
> > I1208 21:13:32.910156 31805 whitelist_watcher.cpp:77] No whitelist given
> > I1208 21:13:32.910637 31809 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> > I1208 21:13:32.911507 31797 recover.cpp:564] Updating replica status to
> VOTING
> > I1208 21:13:32.912325 31797 leveldb.cpp:304] Persisting metadata (8
> bytes) to leveldb took 480213ns
> > I1208 21:13:32.912413 31797 replica.cpp:321] Persisted replica status to
> VOTING
> > I1208 21:13:32.912626 31797 recover.cpp:578] Successfully joined the
> Paxos group
> > I1208 21:13:32.912986 31797 recover.cpp:462] Recover process terminated
> > I1208 21:13:32.912693 31802 master.cpp:1637] The newly elected leader is
> master@172.17.0.1:51123 with id 82f3b2af-5808-46f2-ae60-6bae2d0029cf
> > I1208 21:13:32.913291 31802 master.cpp:1650] Elected as the leading
> master!
> > I1208 21:13:32.913398 31802 master.cpp:1395] Recovering from registrar
> > I1208 21:13:32.913847 31802 registrar.cpp:307] Recovering registrar
> > I1208 21:13:32.914738 31802 log.cpp:659] Attempting to start the writer
> > I1208 21:13:32.917070 31801 replica.cpp:494] Replica received implicit
> promise request from (11495)@172.17.0.1:51123 with proposal 1
> > I1208 21:13:32.917593 31801 leveldb.cpp:304] Persisting metadata (8
> bytes) to leveldb took 417636ns
> > I1208 21:13:32.917620 31801 replica.cpp:343] Persisted promised to 1
> > I1208 21:13:32.918617 31805 coordinator.cpp:238] Coordinator attempting
> to fill missing positions
> > I1208 21:13:32.920080 31809 replica.cpp:389] Replica received explicit
> promise request from (11496)@172.17.0.1:51123 for position 0 with
> proposal 2
> > I1208 21:13:32.920460 31809 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 335179ns
> > I1208 21:13:32.920488 31809 replica.cpp:713] Persisted action at 0
> > I1208 21:13:32.921687 31808 replica.cpp:538] Replica received write
> request for position 0 from (11497)@172.17.0.1:51123
> > I1208 21:13:32.921805 31808 leveldb.cpp:436] Reading position from
> leveldb took 52002ns
> > I1208 21:13:32.922269 31808 leveldb.cpp:341] Persisting action (14
> bytes) to leveldb took 405087ns
> > I1208 21:13:32.922297 31808 replica.cpp:713] Persisted action at 0
> > I1208 21:13:32.923353 31808 replica.cpp:692] Replica received learned
> notice for position 0 from @0.0.0.0:0
> > I1208 21:13:32.923733 31808 leveldb.cpp:341] Persisting action (16
> bytes) to leveldb took 343111ns
> > I1208 21:13:32.923771 31808 replica.cpp:713] Persisted action at 0
> > I1208 21:13:32.923796 31808 replica.cpp:698] Replica learned NOP action
> at position 0
> > I1208 21:13:32.924515 31801 log.cpp:675] Writer started with ending
> position 0
> > I1208 21:13:32.925943 31800 leveldb.cpp:436] Reading position from
> leveldb took 46404ns
> > I1208 21:13:32.927253 31801 registrar.cpp:340] Successfully fetched the
> registry (0B) in 13.302016ms
> > I1208 21:13:32.927388 31801 registrar.cpp:439] Applied 1 operations in
> 34368ns; attempting to update the 'registry'
> > I1208 21:13:32.928573 31801 log.cpp:683] Attempting to append 170 bytes
> to the log
> > I1208 21:13:32.928776 31801 coordinator.cpp:348] Coordinator attempting
> to write APPEND action at position 1
> > I1208 21:13:32.929868 31808 replica.cpp:538] Replica received write
> request for position 1 from (11498)@172.17.0.1:51123
> > I1208 21:13:32.930430 31808 leveldb.cpp:341] Persisting action (189
> bytes) to leveldb took 514150ns
> > I1208 21:13:32.930460 31808 replica.cpp:713] Persisted action at 1
> > I1208 21:13:32.938609 31806 replica.cpp:692] Replica received learned
> notice for position 1 from @0.0.0.0:0
> > I1208 21:13:32.939223 31806 leveldb.cpp:341] Persisting action (191
> bytes) to leveldb took 544975ns
> > I1208 21:13:32.939254 31806 replica.cpp:713] Persisted action at 1
> > I1208 21:13:32.939286 31806 replica.cpp:698] Replica learned APPEND
> action at position 1
> > I1208 21:13:32.940592 31800 registrar.cpp:484] Successfully updated the
> 'registry' in 13.131008ms
> > I1208 21:13:32.940768 31800 registrar.cpp:370] Successfully recovered
> registrar
> > I1208 21:13:32.940899 31806 log.cpp:702] Attempting to truncate the log
> to 1
> > I1208 21:13:32.941201 31807 coordinator.cpp:348] Coordinator attempting
> to write TRUNCATE action at position 2
> > I1208 21:13:32.941354 31800 master.cpp:1447] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> > I1208 21:13:32.941386 31805 hierarchical.cpp:181] Skipping recovery of
> hierarchical allocator: nothing to recover
> > I1208 21:13:32.942443 31804 replica.cpp:538] Replica received write
> request for position 2 from (11499)@172.17.0.1:51123
> > I1208 21:13:32.943066 31804 leveldb.cpp:341] Persisting action (16
> bytes) to leveldb took 575750ns
> > I1208 21:13:32.943095 31804 replica.cpp:713] Persisted action at 2
> > I1208 21:13:32.944013 31806 replica.cpp:692] Replica received learned
> notice for position 2 from @0.0.0.0:0
> > I1208 21:13:32.944552 31806 leveldb.cpp:341] Persisting action (18
> bytes) to leveldb took 487053ns
> > I1208 21:13:32.944629 31806 leveldb.cpp:399] Deleting ~1 keys from
> leveldb took 40536ns
> > I1208 21:13:32.944664 31806 replica.cpp:713] Persisted action at 2
> > I1208 21:13:32.944705 31806 replica.cpp:698] Replica learned TRUNCATE
> action at position 2
> > I1208 21:13:32.953706 31775 scheduler.cpp:154] Version: 0.27.0
> > I1208 21:13:32.954695 31803 scheduler.cpp:236] New master detected at
> master@172.17.0.1:51123
> > I1208 21:13:32.956135 31803 scheduler.cpp:298] Sending SUBSCRIBE call to
> master@172.17.0.1:51123
> > I1208 21:13:32.958519 31808 process.cpp:3077] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> > I1208 21:13:32.958598 31808 http.cpp:336] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.1:33377
> > I1208 21:13:32.958845 31808 master.cpp:1899] Received subscription
> request for HTTP framework 'default'
> > I1208 21:13:32.958930 31808 master.cpp:1676] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> > I1208 21:13:32.959635 31808 master.cpp:1991] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> > I1208 21:13:32.960489 31796 master.hpp:1583] Sending heartbeat to
> 82f3b2af-5808-46f2-ae60-6bae2d0029cf-0000
> > I1208 21:13:32.961225 31799 hierarchical.cpp:267] Added framework
> 82f3b2af-5808-46f2-ae60-6bae2d0029cf-0000
> > I1208 21:13:32.961282 31796 scheduler.cpp:457] Enqueuing event
> SUBSCRIBED received from master@172.17.0.1:51123
> > I1208 21:13:32.961302 31799 hierarchical.cpp:1317] No resources
> available to allocate!
> > I1208 21:13:32.961462 31799 hierarchical.cpp:1410] No inverse offers to
> send out!
> > I1208 21:13:32.961500 31799 hierarchical.cpp:1063] Performed allocation
> for 0 slaves in 245986ns
> > I1208 21:13:32.962980 31800 scheduler.cpp:298] Sending REQUEST call to
> master@172.17.0.1:51123
> > I1208 21:13:32.963606 31800 scheduler.cpp:457] Enqueuing event HEARTBEAT
> received from master@172.17.0.1:51123
> > I1208 21:13:32.964252 31800 master_maintenance_tests.cpp:177] Ignoring
> HEARTBEAT event
> > I1208 21:13:32.964716 31799 process.cpp:3077] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> > I1208 21:13:32.964787 31799 http.cpp:336] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.1:33378
> > I1208 21:13:32.964893 31799 master.cpp:2646] Processing REQUEST call for
> framework 82f3b2af-5808-46f2-ae60-6bae2d0029cf-0000 (default)
> > I1208 21:13:32.965018 31807 hierarchical.cpp:562] Received resource
> request from framework 82f3b2af-5808-46f2-ae60-6bae2d0029cf-0000
> > I1208 21:13:32.965303 31806 master.cpp:938] Master terminating
> > I1208 21:13:32.965538 31803 hierarchical.cpp:308] Removed framework
> 82f3b2af-5808-46f2-ae60-6bae2d0029cf-0000
> > E1208 21:13:32.968647 31806 scheduler.cpp:431] End-Of-File received from
> master. The master closed the event stream
> > [ OK ] ContentType/SchedulerTest.Request/0 (78 ms)
> > [ RUN ] ContentType/SchedulerTest.Request/1
> > I1208 21:13:32.975648 31775 leveldb.cpp:174] Opened db in 2.24527ms
> > I1208 21:13:32.976327 31775 leveldb.cpp:181] Compacted db in 639122ns
> > I1208 21:13:32.976372 31775 leveldb.cpp:196] Created db iterator in
> 18080ns
> > I1208 21:13:32.976389 31775 leveldb.cpp:202] Seeked to beginning of db
> in 1676ns
> > I1208 21:13:32.976400 31775 leveldb.cpp:271] Iterated through 0 keys in
> the db in 222ns
> > I1208 21:13:32.976446 31775 replica.cpp:778] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> > I1208 21:13:32.977051 31803 recover.cpp:447] Starting replica recovery
> > I1208 21:13:32.977452 31803 recover.cpp:473] Replica is in EMPTY status
> > I1208 21:13:32.979074 31804 replica.cpp:674] Replica in EMPTY status
> received a broadcasted recover request from (11504)@172.17.0.1:51123
> > I1208 21:13:32.979714 31801 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> > I1208 21:13:32.981096 31800 recover.cpp:564] Updating replica status to
> STARTING
> > I1208 21:13:32.981772 31800 leveldb.cpp:304] Persisting metadata (8
> bytes) to leveldb took 495034ns
> > I1208 21:13:32.981981 31800 replica.cpp:321] Persisted replica status to
> STARTING
> > I1208 21:13:32.983151 31798 recover.cpp:473] Replica is in STARTING
> status
> > I1208 21:13:32.983314 31795 master.cpp:365] Master
> f8764117-369a-4071-b13e-17a51f6f7ffd (f652123f5286) started on
> 172.17.0.1:51123
> > I1208 21:13:32.983537 31795 master.cpp:367] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_slaves="true"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/wpyUKH/credentials" --framework_sorter="drf"
> --help="false" --hostname_lookup="true" --initialize_driver_logging="true"
> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> --max_slave_ping_timeouts="5" --quiet="false"
> --recovery_slave_removal_limit="100%" --registry="replicated_log"
> --registry_fetch_timeout="1mins" --registry_store_timeout="25secs"
> --registry_strict="true" --root_submissions="true"
> --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins"
> --user_sorter="drf" --version="false"
> --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui"
> --work_dir="/tmp/wpyUKH/master" --zk_session_timeout="10secs"
> > I1208 21:13:32.984084 31795 master.cpp:414] Master allowing
> unauthenticated frameworks to register
> > I1208 21:13:32.984112 31795 master.cpp:417] Master only allowing
> authenticated slaves to register
> > I1208 21:13:32.984122 31795 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/wpyUKH/credentials'
> > I1208 21:13:32.984542 31795 master.cpp:456] Using default 'crammd5'
> authenticator
> > I1208 21:13:32.986073 31798 replica.cpp:674] Replica in STARTING status
> received a broadcasted recover request from (11505)@172.17.0.1:51123
> > I1208 21:13:32.986407 31795 master.cpp:493] Authorization enabled
> > I1208 21:13:32.986498 31803 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> > I1208 21:13:32.986698 31808 whitelist_watcher.cpp:77] No whitelist given
> > I1208 21:13:32.986721 31798 hierarchical.cpp:163] Initialized
> hierarchical allocator process
> > I1208 21:13:32.987228 31803 recover.cpp:564] Updating replica status to
> VOTING
> > I1208 21:13:32.987905 31805 leveldb.cpp:304] Persisting metadata (8
> bytes) to leveldb took 521694ns
> > I1208 21:13:32.987937 31805 replica.cpp:321] Persisted replica status to
> VOTING
> > I1208 21:13:32.988183 31803 recover.cpp:578] Successfully joined the
> Paxos group
> > I1208 21:13:32.988435 31803 recover.cpp:462] Recover process terminated
> > I1208 21:13:32.989279 31796 master.cpp:1637] The newly elected leader is
> master@172.17.0.1:51123 with id f8764117-369a-4071-b13e-17a51f6f7ffd
> > I1208 21:13:32.989311 31796 master.cpp:1650] Elected as the leading
> master!
> > I1208 21:13:32.989330 31796 master.cpp:1395] Recovering from registrar
> > I1208 21:13:32.989565 31796 registrar.cpp:307] Recovering registrar
> > I1208 21:13:32.990625 31807 log.cpp:659] Attempting to start the writer
> > I1208 21:13:32.993171 31795 replica.cpp:494] Replica received implicit
> promise request from (11506)@172.17.0.1:51123 with proposal 1
> > I1208 21:13:32.993702 31795 leveldb.cpp:304] Persisting metadata (8
> bytes) to leveldb took 403968ns
> > I1208 21:13:32.993783 31795 replica.cpp:343] Persisted promised to 1
> > I1208 21:13:32.994575 31804 coordinator.cpp:238] Coordinator attempting
> to fill missing positions
> > I1208 21:13:32.996242 31807 replica.cpp:389] Replica received explicit
> promise request from (11507)@172.17.0.1:51123 for position 0 with
> proposal 2
> > I1208 21:13:32.996676 31807 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 388675ns
> > I1208 21:13:32.996702 31807 replica.cpp:713] Persisted action at 0
> > I1208 21:13:32.997856 31801 replica.cpp:538] Replica received write
> request for position 0 from (11508)@172.17.0.1:51123
> > I1208 21:13:32.998216 31801 leveldb.cpp:436] Reading position from
> leveldb took 33223ns
> > I1208 21:13:32.998778 31801 leveldb.cpp:341] Persisting action (14
> bytes) to leveldb took 315548ns
> > I1208 21:13:32.998991 31801 replica.cpp:713] Persisted action at 0
> > I1208 21:13:32.999815 31801 replica.cpp:692] Replica received learned
> notice for position 0 from @0.0.0.0:0
> > I1208 21:13:33.000452 31801 leveldb.cpp:341] Persisting action (16
> bytes) to leveldb took 605452ns
> > I1208 21:13:33.000479 31801 replica.cpp:713] Persisted action at 0
> > I1208 21:13:33.000499 31801 replica.cpp:698] Replica learned NOP action
> at position 0
> > I1208 21:13:33.001260 31796 log.cpp:675] Writer started with ending
> position 0
> > I1208 21:13:33.002645 31806 leveldb.cpp:436] Reading position from
> leveldb took 61218ns
> > I1208 21:13:33.003988 31794 registrar.cpp:340] Successfully fetched the
> registry (0B) in 14.37312ms
> > I1208 21:13:33.004207 31794 registrar.cpp:439] Applied 1 operations in
> 33883ns; attempting to update the 'registry'
> > I1208 21:13:33.005064 31800 log.cpp:683] Attempting to append 170 bytes
> to the log
> > I1208 21:13:33.005188 31809 coordinator.cpp:348] Coordinator attempting
> to write APPEND action at position 1
> > I1208 21:13:33.006063 31798 replica.cpp:538] Replica received write
> request for position 1 from (11509)@172.17.0.1:51123
> > I1208 21:13:33.006561 31798 leveldb.cpp:341] Persisting action (189
> bytes) to leveldb took 454382ns
> > I1208 21:13:33.006587 31798 replica.cpp:713] Persisted action at 1
> > I1208 21:13:33.007567 31800 replica.cpp:692] Replica received learned
> notice for position 1 from @0.0.0.0:0
> > I1208 21:13:33.008075 31800 leveldb.cpp:341] Persisting action (191
> bytes) to leveldb took 451345ns
> > I1208 21:13:33.008112 31800 replica.cpp:713] Persisted action at 1
> > I1208 21:13:33.008147 31800 replica.cpp:698] Replica learned APPEND
> action at position 1
> > I1208 21:13:33.010313 31806 registrar.cpp:484] Successfully updated the
> 'registry' in 6.008064ms
> > I1208 21:13:33.010702 31806 registrar.cpp:370] Successfully recovered
> registrar
> > I1208 21:13:33.011247 31805 log.cpp:702] Attempting to truncate the log
> to 1
> > I1208 21:13:33.012493 31803 coordinator.cpp:348] Coordinator attempting
> to write TRUNCATE action at position 2
> > I1208 21:13:33.012821 31797 master.cpp:1447] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> > I1208 21:13:33.012935 31797 hierarchical.cpp:181] Skipping recovery of
> hierarchical allocator: nothing to recover
> > I1208 21:13:33.013968 31807 replica.cpp:538] Replica received write
> request for position 2 from (11510)@172.17.0.1:51123
> > I1208 21:13:33.014521 31807 leveldb.cpp:341] Persisting action (16
> bytes) to leveldb took 478545ns
> > I1208 21:13:33.014552 31807 replica.cpp:713] Persisted action at 2
> > I1208 21:13:33.015481 31807 replica.cpp:692] Replica received learned
> notice for position 2 from @0.0.0.0:0
> > I1208 21:13:33.015897 31807 leveldb.cpp:341] Persisting action (18
> bytes) to leveldb took 308611ns
> > I1208 21:13:33.016042 31807 leveldb.cpp:399] Deleting ~1 keys from
> leveldb took 47319ns
> > I1208 21:13:33.016083 31807 replica.cpp:713] Persisted action at 2
> > I1208 21:13:33.016109 31807 replica.cpp:698] Replica learned TRUNCATE
> action at position 2
> > I1208 21:13:33.023864 31775 scheduler.cpp:154] Version: 0.27.0
> > I1208 21:13:33.024884 31803 scheduler.cpp:236] New master detected at
> master@172.17.0.1:51123
> > I1208 21:13:33.026504 31806 scheduler.cpp:298] Sending SUBSCRIBE call to
> master@172.17.0.1:51123
> > I1208 21:13:33.029641 31799 process.cpp:3077] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> > I1208 21:13:33.029713 31799 http.cpp:336] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.1:33379
> > I1208 21:13:33.030135 31799 master.cpp:1899] Received subscription
> request for HTTP framework 'default'
> > I1208 21:13:33.030220 31799 master.cpp:1676] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> > I1208 21:13:33.030812 31802 master.cpp:1991] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> > I1208 21:13:33.032304 31796 hierarchical.cpp:267] Added framework
> f8764117-369a-4071-b13e-17a51f6f7ffd-0000
> > I1208 21:13:33.032318 31802 master.hpp:1583] Sending heartbeat to
> f8764117-369a-4071-b13e-17a51f6f7ffd-0000
> > I1208 21:13:33.032384 31796 hierarchical.cpp:1317] No resources
> available to allocate!
> > I1208 21:13:33.032418 31796 hierarchical.cpp:1410] No inverse offers to
> send out!
> > I1208 21:13:33.032444 31796 hierarchical.cpp:1063] Performed allocation
> for 0 slaves in 114998ns
> > I1208 21:13:33.033583 31799 scheduler.cpp:457] Enqueuing event
> SUBSCRIBED received from master@172.17.0.1:51123
> > I1208 21:13:33.033951 31799 scheduler.cpp:457] Enqueuing event HEARTBEAT
> received from master@172.17.0.1:51123
> > I1208 21:13:33.034461 31806 master_maintenance_tests.cpp:177] Ignoring
> HEARTBEAT event
> > I1208 21:13:33.035090 31801 scheduler.cpp:298] Sending REQUEST call to
> master@172.17.0.1:51123
> > I1208 21:13:33.037539 31807 process.cpp:3077] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> > I1208 21:13:33.037637 31807 http.cpp:336] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.1:33380
> > I1208 21:13:33.037961 31807 master.cpp:2646] Processing REQUEST call for
> framework f8764117-369a-4071-b13e-17a51f6f7ffd-0000 (default)
> > I1208 21:13:33.038218 31805 hierarchical.cpp:562] Received resource
> request from framework f8764117-369a-4071-b13e-17a51f6f7ffd-0000
> > I1208 21:13:33.038645 31805 master.cpp:938] Master terminating
> > I1208 21:13:33.038851 31809 hierarchical.cpp:308] Removed framework
> f8764117-369a-4071-b13e-17a51f6f7ffd-0000
> > E1208 21:13:33.040077 31805 scheduler.cpp:431] End-Of-File received from
> master. The master closed the event stream
> > [ OK ] ContentType/SchedulerTest.Request/1 (73 ms)
> > [----------] 22 tests from ContentType/SchedulerTest (4531 ms total)
> >
> > [----------] Global test environment tear-down
> > [==========] 886 tests from 116 test cases ran. (367515 ms total)
> > [ PASSED ] 885 tests.
> > [ FAILED ] 1 test, listed below:
> > [ FAILED ] HealthTest.ObserveEndpoint
> >
> > 1 FAILED TEST
> > YOU HAVE 7 DISABLED TESTS
> >
> > make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> > make[4]: *** [check-local] Error 1
> > make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> > make[3]: *** [check-am] Error 2
> > make[2]: *** [check] Error 2
> > make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> > make[1]: *** [check-recursive] Error 1
> > make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
> > make: *** [distcheck] Error 1
> > + docker rmi mesos-1449606905-25998
> > Untagged: mesos-1449606905-25998:latest
> > Deleted: fdff04de0f52f84893cf5b01b069d65acd64d4feb6d5e1a02ef92f0c9eef4be4
> > Deleted: cd33e351a3abec2b2690c0de755c255c8bb347e3e1ea6a05c14c2e92bfef35dc
> > Deleted: f6092593961087fef619cfbbcb9a36b758e9875e6af3c92720c322897c02eeea
> > Deleted: 6de705835c0a9ad1ba9da6d73ae441e92759b069b218b410ea1d925c5ca8c688
> > Deleted: c2df9525e3dbfa57ca33d1cd2085bedded75a0b70bc6a1d532a1d7aed0dd9d2c
> > Deleted: 7d4cb399e41136eb94d74b2f52dbcdff8524a19ea47989ab54cb6112020fac14
> > Deleted: f31ffac0badc2531939e1464bb7aa793582b49de3ac6892ce51ad2c871e8638f
> > Deleted: 08c83f598fd5ad801bc21567afe9c48d9b32baae044988259e34bf374c67fd52
> > Deleted: 78041b6f0444fb0b4e429c6d822d766fa1d85beb868517da161e611a3b5e8ee8
> > Deleted: 2d9b6f9c813df223123fd206292b29d1409958dd6f1ee5c8519caad249994202
> > Deleted: c4b8076d485aa9f7ab196ff5324c8c91368224e82ef95d4b9f4e083f164e295a
> > Deleted: dffbe3fcd0e915faaaead626d8468e17e8a34f9486addda69601df7476e275bd
> > Deleted: 2b024206eeb74c6853b44d003aa189ca010fe08856e83fad57b4ec0024b8f770
> > Build step 'Execute shell' marked build as failure
>
Re: Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #1331
Posted by Neil Conway <ne...@gmail.com>.
This build failure is due to a broken test
(HealthTest.ObserveEndpoint), and has already been fixed in master:
https://reviews.apache.org/r/41100/
Neil
On Tue, Dec 8, 2015 at 1:13 PM, Apache Jenkins Server
<je...@builds.apache.org> wrote:
> See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1331/>
>
> ------------------------------------------
> [...truncated 149982 lines...]
> I1208 21:13:32.888731 31805 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_UcnUDi/slaves/4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-S0/frameworks/4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-0000/executors/default/runs/5042430f-2899-4d52-9124-7c8072b1f90c' for gc 6.99998971481481days in the future
> I1208 21:13:32.888869 31806 slave.cpp:3947] Cleaning up framework 4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-0000
> I1208 21:13:32.888994 31804 status_update_manager.cpp:282] Closing status update streams for framework 4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-0000
> I1208 21:13:32.889000 31805 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_UcnUDi/slaves/4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-S0/frameworks/4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-0000/executors/default' for gc 6.99998971283556days in the future
> I1208 21:13:32.889173 31804 status_update_manager.cpp:528] Cleaning up status update stream for task ce556009-8357-4b71-ae64-32efac0c6a76 of framework 4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-0000
> I1208 21:13:32.889294 31805 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_UcnUDi/slaves/4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-S0/frameworks/4df7a4d2-ec02-4b66-b29a-6e32f081f4b3-0000' for gc 6.99998971096days in the future
> [ OK ] ContentType/SchedulerTest.Message/1 (116 ms)
> [ RUN ] ContentType/SchedulerTest.Request/0
> I1208 21:13:32.900418 31775 leveldb.cpp:174] Opened db in 5.410505ms
> I1208 21:13:32.901538 31775 leveldb.cpp:181] Compacted db in 1.036746ms
> I1208 21:13:32.901629 31775 leveldb.cpp:196] Created db iterator in 25385ns
> I1208 21:13:32.901646 31775 leveldb.cpp:202] Seeked to beginning of db in 2077ns
> I1208 21:13:32.901657 31775 leveldb.cpp:271] Iterated through 0 keys in the db in 345ns
> I1208 21:13:32.901715 31775 replica.cpp:778] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
> I1208 21:13:32.902657 31796 recover.cpp:447] Starting replica recovery
> I1208 21:13:32.903240 31795 recover.cpp:473] Replica is in EMPTY status
> I1208 21:13:32.904693 31798 replica.cpp:674] Replica in EMPTY status received a broadcasted recover request from (11493)@172.17.0.1:51123
> I1208 21:13:32.905571 31806 recover.cpp:193] Received a recover response from a replica in EMPTY status
> I1208 21:13:32.906330 31805 recover.cpp:564] Updating replica status to STARTING
> I1208 21:13:32.907173 31803 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 656317ns
> I1208 21:13:32.907210 31803 replica.cpp:321] Persisted replica status to STARTING
> I1208 21:13:32.907413 31803 recover.cpp:473] Replica is in STARTING status
> I1208 21:13:32.908320 31802 master.cpp:365] Master 82f3b2af-5808-46f2-ae60-6bae2d0029cf (f652123f5286) started on 172.17.0.1:51123
> I1208 21:13:32.908345 31802 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/N8LyKl/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/N8LyKl/master" --zk_session_timeout="10secs"
> I1208 21:13:32.908740 31802 master.cpp:414] Master allowing unauthenticated frameworks to register
> I1208 21:13:32.908751 31802 master.cpp:417] Master only allowing authenticated slaves to register
> I1208 21:13:32.908759 31802 credentials.hpp:35] Loading credentials for authentication from '/tmp/N8LyKl/credentials'
> I1208 21:13:32.909150 31802 master.cpp:456] Using default 'crammd5' authenticator
> I1208 21:13:32.909302 31802 master.cpp:493] Authorization enabled
> I1208 21:13:32.909888 31803 hierarchical.cpp:163] Initialized hierarchical allocator process
> I1208 21:13:32.909265 31805 replica.cpp:674] Replica in STARTING status received a broadcasted recover request from (11494)@172.17.0.1:51123
> I1208 21:13:32.910156 31805 whitelist_watcher.cpp:77] No whitelist given
> I1208 21:13:32.910637 31809 recover.cpp:193] Received a recover response from a replica in STARTING status
> I1208 21:13:32.911507 31797 recover.cpp:564] Updating replica status to VOTING
> I1208 21:13:32.912325 31797 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 480213ns
> I1208 21:13:32.912413 31797 replica.cpp:321] Persisted replica status to VOTING
> I1208 21:13:32.912626 31797 recover.cpp:578] Successfully joined the Paxos group
> I1208 21:13:32.912986 31797 recover.cpp:462] Recover process terminated
> I1208 21:13:32.912693 31802 master.cpp:1637] The newly elected leader is master@172.17.0.1:51123 with id 82f3b2af-5808-46f2-ae60-6bae2d0029cf
> I1208 21:13:32.913291 31802 master.cpp:1650] Elected as the leading master!
> I1208 21:13:32.913398 31802 master.cpp:1395] Recovering from registrar
> I1208 21:13:32.913847 31802 registrar.cpp:307] Recovering registrar
> I1208 21:13:32.914738 31802 log.cpp:659] Attempting to start the writer
> I1208 21:13:32.917070 31801 replica.cpp:494] Replica received implicit promise request from (11495)@172.17.0.1:51123 with proposal 1
> I1208 21:13:32.917593 31801 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 417636ns
> I1208 21:13:32.917620 31801 replica.cpp:343] Persisted promised to 1
> I1208 21:13:32.918617 31805 coordinator.cpp:238] Coordinator attempting to fill missing positions
> I1208 21:13:32.920080 31809 replica.cpp:389] Replica received explicit promise request from (11496)@172.17.0.1:51123 for position 0 with proposal 2
> I1208 21:13:32.920460 31809 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 335179ns
> I1208 21:13:32.920488 31809 replica.cpp:713] Persisted action at 0
> I1208 21:13:32.921687 31808 replica.cpp:538] Replica received write request for position 0 from (11497)@172.17.0.1:51123
> I1208 21:13:32.921805 31808 leveldb.cpp:436] Reading position from leveldb took 52002ns
> I1208 21:13:32.922269 31808 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 405087ns
> I1208 21:13:32.922297 31808 replica.cpp:713] Persisted action at 0
> I1208 21:13:32.923353 31808 replica.cpp:692] Replica received learned notice for position 0 from @0.0.0.0:0
> I1208 21:13:32.923733 31808 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 343111ns
> I1208 21:13:32.923771 31808 replica.cpp:713] Persisted action at 0
> I1208 21:13:32.923796 31808 replica.cpp:698] Replica learned NOP action at position 0
> I1208 21:13:32.924515 31801 log.cpp:675] Writer started with ending position 0
> I1208 21:13:32.925943 31800 leveldb.cpp:436] Reading position from leveldb took 46404ns
> I1208 21:13:32.927253 31801 registrar.cpp:340] Successfully fetched the registry (0B) in 13.302016ms
> I1208 21:13:32.927388 31801 registrar.cpp:439] Applied 1 operations in 34368ns; attempting to update the 'registry'
> I1208 21:13:32.928573 31801 log.cpp:683] Attempting to append 170 bytes to the log
> I1208 21:13:32.928776 31801 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
> I1208 21:13:32.929868 31808 replica.cpp:538] Replica received write request for position 1 from (11498)@172.17.0.1:51123
> I1208 21:13:32.930430 31808 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 514150ns
> I1208 21:13:32.930460 31808 replica.cpp:713] Persisted action at 1
> I1208 21:13:32.938609 31806 replica.cpp:692] Replica received learned notice for position 1 from @0.0.0.0:0
> I1208 21:13:32.939223 31806 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 544975ns
> I1208 21:13:32.939254 31806 replica.cpp:713] Persisted action at 1
> I1208 21:13:32.939286 31806 replica.cpp:698] Replica learned APPEND action at position 1
> I1208 21:13:32.940592 31800 registrar.cpp:484] Successfully updated the 'registry' in 13.131008ms
> I1208 21:13:32.940768 31800 registrar.cpp:370] Successfully recovered registrar
> I1208 21:13:32.940899 31806 log.cpp:702] Attempting to truncate the log to 1
> I1208 21:13:32.941201 31807 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
> I1208 21:13:32.941354 31800 master.cpp:1447] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
> I1208 21:13:32.941386 31805 hierarchical.cpp:181] Skipping recovery of hierarchical allocator: nothing to recover
> I1208 21:13:32.942443 31804 replica.cpp:538] Replica received write request for position 2 from (11499)@172.17.0.1:51123
> I1208 21:13:32.943066 31804 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 575750ns
> I1208 21:13:32.943095 31804 replica.cpp:713] Persisted action at 2
> I1208 21:13:32.944013 31806 replica.cpp:692] Replica received learned notice for position 2 from @0.0.0.0:0
> I1208 21:13:32.944552 31806 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 487053ns
> I1208 21:13:32.944629 31806 leveldb.cpp:399] Deleting ~1 keys from leveldb took 40536ns
> I1208 21:13:32.944664 31806 replica.cpp:713] Persisted action at 2
> I1208 21:13:32.944705 31806 replica.cpp:698] Replica learned TRUNCATE action at position 2
> I1208 21:13:32.953706 31775 scheduler.cpp:154] Version: 0.27.0
> I1208 21:13:32.954695 31803 scheduler.cpp:236] New master detected at master@172.17.0.1:51123
> I1208 21:13:32.956135 31803 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.1:51123
> I1208 21:13:32.958519 31808 process.cpp:3077] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
> I1208 21:13:32.958598 31808 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:33377
> I1208 21:13:32.958845 31808 master.cpp:1899] Received subscription request for HTTP framework 'default'
> I1208 21:13:32.958930 31808 master.cpp:1676] Authorizing framework principal 'test-principal' to receive offers for role '*'
> I1208 21:13:32.959635 31808 master.cpp:1991] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
> I1208 21:13:32.960489 31796 master.hpp:1583] Sending heartbeat to 82f3b2af-5808-46f2-ae60-6bae2d0029cf-0000
> I1208 21:13:32.961225 31799 hierarchical.cpp:267] Added framework 82f3b2af-5808-46f2-ae60-6bae2d0029cf-0000
> I1208 21:13:32.961282 31796 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.1:51123
> I1208 21:13:32.961302 31799 hierarchical.cpp:1317] No resources available to allocate!
> I1208 21:13:32.961462 31799 hierarchical.cpp:1410] No inverse offers to send out!
> I1208 21:13:32.961500 31799 hierarchical.cpp:1063] Performed allocation for 0 slaves in 245986ns
> I1208 21:13:32.962980 31800 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.1:51123
> I1208 21:13:32.963606 31800 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.1:51123
> I1208 21:13:32.964252 31800 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
> I1208 21:13:32.964716 31799 process.cpp:3077] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
> I1208 21:13:32.964787 31799 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:33378
> I1208 21:13:32.964893 31799 master.cpp:2646] Processing REQUEST call for framework 82f3b2af-5808-46f2-ae60-6bae2d0029cf-0000 (default)
> I1208 21:13:32.965018 31807 hierarchical.cpp:562] Received resource request from framework 82f3b2af-5808-46f2-ae60-6bae2d0029cf-0000
> I1208 21:13:32.965303 31806 master.cpp:938] Master terminating
> I1208 21:13:32.965538 31803 hierarchical.cpp:308] Removed framework 82f3b2af-5808-46f2-ae60-6bae2d0029cf-0000
> E1208 21:13:32.968647 31806 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/0 (78 ms)
> [ RUN ] ContentType/SchedulerTest.Request/1
> I1208 21:13:32.975648 31775 leveldb.cpp:174] Opened db in 2.24527ms
> I1208 21:13:32.976327 31775 leveldb.cpp:181] Compacted db in 639122ns
> I1208 21:13:32.976372 31775 leveldb.cpp:196] Created db iterator in 18080ns
> I1208 21:13:32.976389 31775 leveldb.cpp:202] Seeked to beginning of db in 1676ns
> I1208 21:13:32.976400 31775 leveldb.cpp:271] Iterated through 0 keys in the db in 222ns
> I1208 21:13:32.976446 31775 replica.cpp:778] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
> I1208 21:13:32.977051 31803 recover.cpp:447] Starting replica recovery
> I1208 21:13:32.977452 31803 recover.cpp:473] Replica is in EMPTY status
> I1208 21:13:32.979074 31804 replica.cpp:674] Replica in EMPTY status received a broadcasted recover request from (11504)@172.17.0.1:51123
> I1208 21:13:32.979714 31801 recover.cpp:193] Received a recover response from a replica in EMPTY status
> I1208 21:13:32.981096 31800 recover.cpp:564] Updating replica status to STARTING
> I1208 21:13:32.981772 31800 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 495034ns
> I1208 21:13:32.981981 31800 replica.cpp:321] Persisted replica status to STARTING
> I1208 21:13:32.983151 31798 recover.cpp:473] Replica is in STARTING status
> I1208 21:13:32.983314 31795 master.cpp:365] Master f8764117-369a-4071-b13e-17a51f6f7ffd (f652123f5286) started on 172.17.0.1:51123
> I1208 21:13:32.983537 31795 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/wpyUKH/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/wpyUKH/master" --zk_session_timeout="10secs"
> I1208 21:13:32.984084 31795 master.cpp:414] Master allowing unauthenticated frameworks to register
> I1208 21:13:32.984112 31795 master.cpp:417] Master only allowing authenticated slaves to register
> I1208 21:13:32.984122 31795 credentials.hpp:35] Loading credentials for authentication from '/tmp/wpyUKH/credentials'
> I1208 21:13:32.984542 31795 master.cpp:456] Using default 'crammd5' authenticator
> I1208 21:13:32.986073 31798 replica.cpp:674] Replica in STARTING status received a broadcasted recover request from (11505)@172.17.0.1:51123
> I1208 21:13:32.986407 31795 master.cpp:493] Authorization enabled
> I1208 21:13:32.986498 31803 recover.cpp:193] Received a recover response from a replica in STARTING status
> I1208 21:13:32.986698 31808 whitelist_watcher.cpp:77] No whitelist given
> I1208 21:13:32.986721 31798 hierarchical.cpp:163] Initialized hierarchical allocator process
> I1208 21:13:32.987228 31803 recover.cpp:564] Updating replica status to VOTING
> I1208 21:13:32.987905 31805 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 521694ns
> I1208 21:13:32.987937 31805 replica.cpp:321] Persisted replica status to VOTING
> I1208 21:13:32.988183 31803 recover.cpp:578] Successfully joined the Paxos group
> I1208 21:13:32.988435 31803 recover.cpp:462] Recover process terminated
> I1208 21:13:32.989279 31796 master.cpp:1637] The newly elected leader is master@172.17.0.1:51123 with id f8764117-369a-4071-b13e-17a51f6f7ffd
> I1208 21:13:32.989311 31796 master.cpp:1650] Elected as the leading master!
> I1208 21:13:32.989330 31796 master.cpp:1395] Recovering from registrar
> I1208 21:13:32.989565 31796 registrar.cpp:307] Recovering registrar
> I1208 21:13:32.990625 31807 log.cpp:659] Attempting to start the writer
> I1208 21:13:32.993171 31795 replica.cpp:494] Replica received implicit promise request from (11506)@172.17.0.1:51123 with proposal 1
> I1208 21:13:32.993702 31795 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 403968ns
> I1208 21:13:32.993783 31795 replica.cpp:343] Persisted promised to 1
> I1208 21:13:32.994575 31804 coordinator.cpp:238] Coordinator attempting to fill missing positions
> I1208 21:13:32.996242 31807 replica.cpp:389] Replica received explicit promise request from (11507)@172.17.0.1:51123 for position 0 with proposal 2
> I1208 21:13:32.996676 31807 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 388675ns
> I1208 21:13:32.996702 31807 replica.cpp:713] Persisted action at 0
> I1208 21:13:32.997856 31801 replica.cpp:538] Replica received write request for position 0 from (11508)@172.17.0.1:51123
> I1208 21:13:32.998216 31801 leveldb.cpp:436] Reading position from leveldb took 33223ns
> I1208 21:13:32.998778 31801 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 315548ns
> I1208 21:13:32.998991 31801 replica.cpp:713] Persisted action at 0
> I1208 21:13:32.999815 31801 replica.cpp:692] Replica received learned notice for position 0 from @0.0.0.0:0
> I1208 21:13:33.000452 31801 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 605452ns
> I1208 21:13:33.000479 31801 replica.cpp:713] Persisted action at 0
> I1208 21:13:33.000499 31801 replica.cpp:698] Replica learned NOP action at position 0
> I1208 21:13:33.001260 31796 log.cpp:675] Writer started with ending position 0
> I1208 21:13:33.002645 31806 leveldb.cpp:436] Reading position from leveldb took 61218ns
> I1208 21:13:33.003988 31794 registrar.cpp:340] Successfully fetched the registry (0B) in 14.37312ms
> I1208 21:13:33.004207 31794 registrar.cpp:439] Applied 1 operations in 33883ns; attempting to update the 'registry'
> I1208 21:13:33.005064 31800 log.cpp:683] Attempting to append 170 bytes to the log
> I1208 21:13:33.005188 31809 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
> I1208 21:13:33.006063 31798 replica.cpp:538] Replica received write request for position 1 from (11509)@172.17.0.1:51123
> I1208 21:13:33.006561 31798 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 454382ns
> I1208 21:13:33.006587 31798 replica.cpp:713] Persisted action at 1
> I1208 21:13:33.007567 31800 replica.cpp:692] Replica received learned notice for position 1 from @0.0.0.0:0
> I1208 21:13:33.008075 31800 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 451345ns
> I1208 21:13:33.008112 31800 replica.cpp:713] Persisted action at 1
> I1208 21:13:33.008147 31800 replica.cpp:698] Replica learned APPEND action at position 1
> I1208 21:13:33.010313 31806 registrar.cpp:484] Successfully updated the 'registry' in 6.008064ms
> I1208 21:13:33.010702 31806 registrar.cpp:370] Successfully recovered registrar
> I1208 21:13:33.011247 31805 log.cpp:702] Attempting to truncate the log to 1
> I1208 21:13:33.012493 31803 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
> I1208 21:13:33.012821 31797 master.cpp:1447] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
> I1208 21:13:33.012935 31797 hierarchical.cpp:181] Skipping recovery of hierarchical allocator: nothing to recover
> I1208 21:13:33.013968 31807 replica.cpp:538] Replica received write request for position 2 from (11510)@172.17.0.1:51123
> I1208 21:13:33.014521 31807 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 478545ns
> I1208 21:13:33.014552 31807 replica.cpp:713] Persisted action at 2
> I1208 21:13:33.015481 31807 replica.cpp:692] Replica received learned notice for position 2 from @0.0.0.0:0
> I1208 21:13:33.015897 31807 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 308611ns
> I1208 21:13:33.016042 31807 leveldb.cpp:399] Deleting ~1 keys from leveldb took 47319ns
> I1208 21:13:33.016083 31807 replica.cpp:713] Persisted action at 2
> I1208 21:13:33.016109 31807 replica.cpp:698] Replica learned TRUNCATE action at position 2
> I1208 21:13:33.023864 31775 scheduler.cpp:154] Version: 0.27.0
> I1208 21:13:33.024884 31803 scheduler.cpp:236] New master detected at master@172.17.0.1:51123
> I1208 21:13:33.026504 31806 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.1:51123
> I1208 21:13:33.029641 31799 process.cpp:3077] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
> I1208 21:13:33.029713 31799 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:33379
> I1208 21:13:33.030135 31799 master.cpp:1899] Received subscription request for HTTP framework 'default'
> I1208 21:13:33.030220 31799 master.cpp:1676] Authorizing framework principal 'test-principal' to receive offers for role '*'
> I1208 21:13:33.030812 31802 master.cpp:1991] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
> I1208 21:13:33.032304 31796 hierarchical.cpp:267] Added framework f8764117-369a-4071-b13e-17a51f6f7ffd-0000
> I1208 21:13:33.032318 31802 master.hpp:1583] Sending heartbeat to f8764117-369a-4071-b13e-17a51f6f7ffd-0000
> I1208 21:13:33.032384 31796 hierarchical.cpp:1317] No resources available to allocate!
> I1208 21:13:33.032418 31796 hierarchical.cpp:1410] No inverse offers to send out!
> I1208 21:13:33.032444 31796 hierarchical.cpp:1063] Performed allocation for 0 slaves in 114998ns
> I1208 21:13:33.033583 31799 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.1:51123
> I1208 21:13:33.033951 31799 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.1:51123
> I1208 21:13:33.034461 31806 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
> I1208 21:13:33.035090 31801 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.1:51123
> I1208 21:13:33.037539 31807 process.cpp:3077] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
> I1208 21:13:33.037637 31807 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:33380
> I1208 21:13:33.037961 31807 master.cpp:2646] Processing REQUEST call for framework f8764117-369a-4071-b13e-17a51f6f7ffd-0000 (default)
> I1208 21:13:33.038218 31805 hierarchical.cpp:562] Received resource request from framework f8764117-369a-4071-b13e-17a51f6f7ffd-0000
> I1208 21:13:33.038645 31805 master.cpp:938] Master terminating
> I1208 21:13:33.038851 31809 hierarchical.cpp:308] Removed framework f8764117-369a-4071-b13e-17a51f6f7ffd-0000
> E1208 21:13:33.040077 31805 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/1 (73 ms)
> [----------] 22 tests from ContentType/SchedulerTest (4531 ms total)
>
> [----------] Global test environment tear-down
> [==========] 886 tests from 116 test cases ran. (367515 ms total)
> [ PASSED ] 885 tests.
> [ FAILED ] 1 test, listed below:
> [ FAILED ] HealthTest.ObserveEndpoint
>
> 1 FAILED TEST
> YOU HAVE 7 DISABLED TESTS
>
> make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> make[4]: *** [check-local] Error 1
> make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> make[3]: *** [check-am] Error 2
> make[2]: *** [check] Error 2
> make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> make[1]: *** [check-recursive] Error 1
> make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
> make: *** [distcheck] Error 1
> + docker rmi mesos-1449606905-25998
> Untagged: mesos-1449606905-25998:latest
> Deleted: fdff04de0f52f84893cf5b01b069d65acd64d4feb6d5e1a02ef92f0c9eef4be4
> Deleted: cd33e351a3abec2b2690c0de755c255c8bb347e3e1ea6a05c14c2e92bfef35dc
> Deleted: f6092593961087fef619cfbbcb9a36b758e9875e6af3c92720c322897c02eeea
> Deleted: 6de705835c0a9ad1ba9da6d73ae441e92759b069b218b410ea1d925c5ca8c688
> Deleted: c2df9525e3dbfa57ca33d1cd2085bedded75a0b70bc6a1d532a1d7aed0dd9d2c
> Deleted: 7d4cb399e41136eb94d74b2f52dbcdff8524a19ea47989ab54cb6112020fac14
> Deleted: f31ffac0badc2531939e1464bb7aa793582b49de3ac6892ce51ad2c871e8638f
> Deleted: 08c83f598fd5ad801bc21567afe9c48d9b32baae044988259e34bf374c67fd52
> Deleted: 78041b6f0444fb0b4e429c6d822d766fa1d85beb868517da161e611a3b5e8ee8
> Deleted: 2d9b6f9c813df223123fd206292b29d1409958dd6f1ee5c8519caad249994202
> Deleted: c4b8076d485aa9f7ab196ff5324c8c91368224e82ef95d4b9f4e083f164e295a
> Deleted: dffbe3fcd0e915faaaead626d8468e17e8a34f9486addda69601df7476e275bd
> Deleted: 2b024206eeb74c6853b44d003aa189ca010fe08856e83fad57b4ec0024b8f770
> Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #1332
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1332/changes>