You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2016/01/20 03:05:32 UTC
Build failed in Jenkins: Mesos » gcc,--verbose,ubuntu:14.04,docker||Hadoop #1514
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1514/changes>
Changes:
[vinodkone] Temporarily disabled EventCallFramework test due to MESOS-3273.
------------------------------------------
[...truncated 158160 lines...]
I0120 02:05:36.613643 31613 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_xEfQ9s/slaves/cc1b5682-e8ef-4902-8fca-8988f1c99e7a-S0/frameworks/cc1b5682-e8ef-4902-8fca-8988f1c99e7a-0000/executors/default' for gc 6.99999291002074days in the future
I0120 02:05:36.613736 31613 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_xEfQ9s/slaves/cc1b5682-e8ef-4902-8fca-8988f1c99e7a-S0/frameworks/cc1b5682-e8ef-4902-8fca-8988f1c99e7a-0000' for gc 6.9999929082637days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (595 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0120 02:05:36.724845 31583 leveldb.cpp:174] Opened db in 98.53574ms
I0120 02:05:36.758622 31583 leveldb.cpp:181] Compacted db in 33.696595ms
I0120 02:05:36.758719 31583 leveldb.cpp:196] Created db iterator in 27470ns
I0120 02:05:36.758739 31583 leveldb.cpp:202] Seeked to beginning of db in 3407ns
I0120 02:05:36.758751 31583 leveldb.cpp:271] Iterated through 0 keys in the db in 245ns
I0120 02:05:36.758806 31583 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0120 02:05:36.759569 31603 recover.cpp:447] Starting replica recovery
I0120 02:05:36.759866 31603 recover.cpp:473] Replica is in EMPTY status
I0120 02:05:36.761332 31607 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13722)@172.17.0.5:58640
I0120 02:05:36.762434 31614 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0120 02:05:36.763751 31606 recover.cpp:564] Updating replica status to STARTING
I0120 02:05:36.766090 31615 master.cpp:374] Master cc03c74e-ae61-4cc8-a1de-387aa699cd20 (0d4d8375089a) started on 172.17.0.5:58640
I0120 02:05:36.766131 31615 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/pGEYQi/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="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/pGEYQi/master" --zk_session_timeout="10secs"
I0120 02:05:36.766552 31615 master.cpp:423] Master allowing unauthenticated frameworks to register
I0120 02:05:36.766566 31615 master.cpp:426] Master only allowing authenticated slaves to register
I0120 02:05:36.766576 31615 credentials.hpp:35] Loading credentials for authentication from '/tmp/pGEYQi/credentials'
I0120 02:05:36.767047 31615 master.cpp:466] Using default 'crammd5' authenticator
I0120 02:05:36.767241 31615 master.cpp:535] Using default 'basic' HTTP authenticator
I0120 02:05:36.767390 31615 master.cpp:569] Authorization enabled
I0120 02:05:36.768007 31602 hierarchical.cpp:145] Initialized hierarchical allocator process
I0120 02:05:36.767779 31610 whitelist_watcher.cpp:77] No whitelist given
I0120 02:05:36.770701 31615 master.cpp:1710] The newly elected leader is master@172.17.0.5:58640 with id cc03c74e-ae61-4cc8-a1de-387aa699cd20
I0120 02:05:36.770858 31615 master.cpp:1723] Elected as the leading master!
I0120 02:05:36.770998 31615 master.cpp:1468] Recovering from registrar
I0120 02:05:36.771270 31604 registrar.cpp:307] Recovering registrar
I0120 02:05:36.801002 31606 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 36.90598ms
I0120 02:05:36.801110 31606 replica.cpp:320] Persisted replica status to STARTING
I0120 02:05:36.801597 31615 recover.cpp:473] Replica is in STARTING status
I0120 02:05:36.802916 31606 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13724)@172.17.0.5:58640
I0120 02:05:36.803705 31615 recover.cpp:193] Received a recover response from a replica in STARTING status
I0120 02:05:36.804419 31608 recover.cpp:564] Updating replica status to VOTING
I0120 02:05:36.834411 31602 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 29.838355ms
I0120 02:05:36.834487 31602 replica.cpp:320] Persisted replica status to VOTING
I0120 02:05:36.834717 31607 recover.cpp:578] Successfully joined the Paxos group
I0120 02:05:36.834997 31607 recover.cpp:462] Recover process terminated
I0120 02:05:36.835764 31616 log.cpp:659] Attempting to start the writer
I0120 02:05:36.837440 31611 replica.cpp:493] Replica received implicit promise request from (13725)@172.17.0.5:58640 with proposal 1
I0120 02:05:36.859557 31611 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.056591ms
I0120 02:05:36.859642 31611 replica.cpp:342] Persisted promised to 1
I0120 02:05:36.860484 31607 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0120 02:05:36.861753 31608 replica.cpp:388] Replica received explicit promise request from (13726)@172.17.0.5:58640 for position 0 with proposal 2
I0120 02:05:36.884680 31608 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.85458ms
I0120 02:05:36.884757 31608 replica.cpp:712] Persisted action at 0
I0120 02:05:36.886225 31607 replica.cpp:537] Replica received write request for position 0 from (13727)@172.17.0.5:58640
I0120 02:05:36.886345 31607 leveldb.cpp:436] Reading position from leveldb took 53484ns
I0120 02:05:36.939693 31607 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 53.275877ms
I0120 02:05:36.939785 31607 replica.cpp:712] Persisted action at 0
I0120 02:05:36.940711 31615 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0120 02:05:37.006469 31615 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 65.679436ms
I0120 02:05:37.006553 31615 replica.cpp:712] Persisted action at 0
I0120 02:05:37.006592 31615 replica.cpp:697] Replica learned NOP action at position 0
I0120 02:05:37.007726 31603 log.cpp:675] Writer started with ending position 0
I0120 02:05:37.009013 31617 leveldb.cpp:436] Reading position from leveldb took 80236ns
I0120 02:05:37.010120 31605 registrar.cpp:340] Successfully fetched the registry (0B) in 238.779904ms
I0120 02:05:37.010267 31605 registrar.cpp:439] Applied 1 operations in 36262ns; attempting to update the 'registry'
I0120 02:05:37.011092 31609 log.cpp:683] Attempting to append 170 bytes to the log
I0120 02:05:37.011240 31614 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0120 02:05:37.012075 31609 replica.cpp:537] Replica received write request for position 1 from (13728)@172.17.0.5:58640
I0120 02:05:37.064991 31609 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 52.834912ms
I0120 02:05:37.065095 31609 replica.cpp:712] Persisted action at 1
I0120 02:05:37.066750 31612 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0120 02:05:37.093667 31612 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 26.849586ms
I0120 02:05:37.093777 31612 replica.cpp:712] Persisted action at 1
I0120 02:05:37.093819 31612 replica.cpp:697] Replica learned APPEND action at position 1
I0120 02:05:37.096192 31612 registrar.cpp:484] Successfully updated the 'registry' in 85.858816ms
I0120 02:05:37.096344 31612 registrar.cpp:370] Successfully recovered registrar
I0120 02:05:37.096621 31612 log.cpp:702] Attempting to truncate the log to 1
I0120 02:05:37.097081 31612 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0120 02:05:37.097179 31612 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0120 02:05:37.097612 31612 hierarchical.cpp:172] Skipping recovery of hierarchical allocator: nothing to recover
I0120 02:05:37.098726 31614 replica.cpp:537] Replica received write request for position 2 from (13729)@172.17.0.5:58640
I0120 02:05:37.118737 31614 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 19.945665ms
I0120 02:05:37.118826 31614 replica.cpp:712] Persisted action at 2
I0120 02:05:37.119779 31611 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
2016-01-20 02:05:37,144:31583(0x2b14c4401700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:41699] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I0120 02:05:37.157114 31611 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 37.268871ms
I0120 02:05:37.157290 31611 leveldb.cpp:399] Deleting ~1 keys from leveldb took 84301ns
I0120 02:05:37.157320 31611 replica.cpp:712] Persisted action at 2
I0120 02:05:37.157359 31611 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0120 02:05:37.159231 31583 scheduler.cpp:154] Version: 0.27.0
I0120 02:05:37.160296 31612 scheduler.cpp:236] New master detected at master@172.17.0.5:58640
I0120 02:05:37.161638 31612 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:58640
I0120 02:05:37.164237 31612 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0120 02:05:37.164907 31603 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:38745
I0120 02:05:37.165174 31603 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0120 02:05:37.165251 31603 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0120 02:05:37.165557 31603 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0120 02:05:37.166157 31607 hierarchical.cpp:266] Added framework cc03c74e-ae61-4cc8-a1de-387aa699cd20-0000
I0120 02:05:37.166256 31607 hierarchical.cpp:1345] No resources available to allocate!
I0120 02:05:37.166291 31607 hierarchical.cpp:1439] No inverse offers to send out!
I0120 02:05:37.166318 31607 hierarchical.cpp:1086] Performed allocation for 0 slaves in 122939ns
I0120 02:05:37.166276 31602 master.hpp:1658] Sending heartbeat to cc03c74e-ae61-4cc8-a1de-387aa699cd20-0000
I0120 02:05:37.167464 31607 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:58640
I0120 02:05:37.168010 31607 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:58640
I0120 02:05:37.168733 31607 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0120 02:05:37.169327 31605 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:58640
I0120 02:05:37.172271 31608 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0120 02:05:37.172833 31608 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:38746
I0120 02:05:37.173071 31608 master.cpp:2717] Processing REQUEST call for framework cc03c74e-ae61-4cc8-a1de-387aa699cd20-0000 (default)
I0120 02:05:37.173508 31602 hierarchical.cpp:586] Received resource request from framework cc03c74e-ae61-4cc8-a1de-387aa699cd20-0000
I0120 02:05:37.174892 31583 master.cpp:1025] Master terminating
I0120 02:05:37.176116 31608 hierarchical.cpp:327] Removed framework cc03c74e-ae61-4cc8-a1de-387aa699cd20-0000
E0120 02:05:37.177567 31603 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (565 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0120 02:05:37.285358 31583 leveldb.cpp:174] Opened db in 94.000521ms
I0120 02:05:37.319135 31583 leveldb.cpp:181] Compacted db in 33.689831ms
I0120 02:05:37.319242 31583 leveldb.cpp:196] Created db iterator in 29758ns
I0120 02:05:37.319262 31583 leveldb.cpp:202] Seeked to beginning of db in 4248ns
I0120 02:05:37.319278 31583 leveldb.cpp:271] Iterated through 0 keys in the db in 397ns
I0120 02:05:37.319335 31583 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0120 02:05:37.319994 31607 recover.cpp:447] Starting replica recovery
I0120 02:05:37.320310 31607 recover.cpp:473] Replica is in EMPTY status
I0120 02:05:37.321465 31613 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13737)@172.17.0.5:58640
I0120 02:05:37.321980 31605 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0120 02:05:37.322468 31616 recover.cpp:564] Updating replica status to STARTING
I0120 02:05:37.324654 31606 master.cpp:374] Master f046bd42-2067-445d-87bf-28de6dfa967e (0d4d8375089a) started on 172.17.0.5:58640
I0120 02:05:37.324684 31606 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/IjSltW/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="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/IjSltW/master" --zk_session_timeout="10secs"
I0120 02:05:37.325153 31606 master.cpp:423] Master allowing unauthenticated frameworks to register
I0120 02:05:37.325165 31606 master.cpp:426] Master only allowing authenticated slaves to register
I0120 02:05:37.325173 31606 credentials.hpp:35] Loading credentials for authentication from '/tmp/IjSltW/credentials'
I0120 02:05:37.325497 31606 master.cpp:466] Using default 'crammd5' authenticator
I0120 02:05:37.325636 31606 master.cpp:535] Using default 'basic' HTTP authenticator
I0120 02:05:37.325815 31606 master.cpp:569] Authorization enabled
I0120 02:05:37.326037 31613 whitelist_watcher.cpp:77] No whitelist given
I0120 02:05:37.326030 31603 hierarchical.cpp:145] Initialized hierarchical allocator process
I0120 02:05:37.327630 31610 master.cpp:1710] The newly elected leader is master@172.17.0.5:58640 with id f046bd42-2067-445d-87bf-28de6dfa967e
I0120 02:05:37.327666 31610 master.cpp:1723] Elected as the leading master!
I0120 02:05:37.327692 31610 master.cpp:1468] Recovering from registrar
I0120 02:05:37.327831 31605 registrar.cpp:307] Recovering registrar
I0120 02:05:37.344106 31602 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 21.471088ms
I0120 02:05:37.344203 31602 replica.cpp:320] Persisted replica status to STARTING
I0120 02:05:37.344617 31602 recover.cpp:473] Replica is in STARTING status
I0120 02:05:37.346006 31602 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13739)@172.17.0.5:58640
I0120 02:05:37.346552 31602 recover.cpp:193] Received a recover response from a replica in STARTING status
I0120 02:05:37.347138 31610 recover.cpp:564] Updating replica status to VOTING
I0120 02:05:37.386360 31602 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.064601ms
I0120 02:05:37.386446 31602 replica.cpp:320] Persisted replica status to VOTING
I0120 02:05:37.386718 31602 recover.cpp:578] Successfully joined the Paxos group
I0120 02:05:37.386921 31602 recover.cpp:462] Recover process terminated
I0120 02:05:37.387526 31610 log.cpp:659] Attempting to start the writer
I0120 02:05:37.388918 31610 replica.cpp:493] Replica received implicit promise request from (13740)@172.17.0.5:58640 with proposal 1
I0120 02:05:37.428285 31610 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.318601ms
I0120 02:05:37.428359 31610 replica.cpp:342] Persisted promised to 1
I0120 02:05:37.429132 31602 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0120 02:05:37.430405 31615 replica.cpp:388] Replica received explicit promise request from (13741)@172.17.0.5:58640 for position 0 with proposal 2
I0120 02:05:37.466537 31615 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 36.076479ms
I0120 02:05:37.466617 31615 replica.cpp:712] Persisted action at 0
I0120 02:05:37.468135 31606 replica.cpp:537] Replica received write request for position 0 from (13742)@172.17.0.5:58640
I0120 02:05:37.468216 31606 leveldb.cpp:436] Reading position from leveldb took 42858ns
I0120 02:05:37.500077 31606 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 31.79523ms
I0120 02:05:37.500160 31606 replica.cpp:712] Persisted action at 0
I0120 02:05:37.501258 31606 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0120 02:05:37.533690 31606 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 32.37603ms
I0120 02:05:37.533774 31606 replica.cpp:712] Persisted action at 0
I0120 02:05:37.533808 31606 replica.cpp:697] Replica learned NOP action at position 0
I0120 02:05:37.535087 31616 log.cpp:675] Writer started with ending position 0
I0120 02:05:37.536653 31616 leveldb.cpp:436] Reading position from leveldb took 52048ns
I0120 02:05:37.537794 31609 registrar.cpp:340] Successfully fetched the registry (0B) in 209.910016ms
I0120 02:05:37.537935 31609 registrar.cpp:439] Applied 1 operations in 39020ns; attempting to update the 'registry'
I0120 02:05:37.538696 31609 log.cpp:683] Attempting to append 170 bytes to the log
I0120 02:05:37.538849 31615 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0120 02:05:37.539626 31608 replica.cpp:537] Replica received write request for position 1 from (13743)@172.17.0.5:58640
I0120 02:05:37.570647 31608 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 30.954831ms
I0120 02:05:37.570721 31608 replica.cpp:712] Persisted action at 1
I0120 02:05:37.571758 31607 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0120 02:05:37.604235 31607 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 32.428004ms
I0120 02:05:37.604311 31607 replica.cpp:712] Persisted action at 1
I0120 02:05:37.604341 31607 replica.cpp:697] Replica learned APPEND action at position 1
I0120 02:05:37.605705 31604 registrar.cpp:484] Successfully updated the 'registry' in 67.686912ms
I0120 02:05:37.605860 31604 registrar.cpp:370] Successfully recovered registrar
I0120 02:05:37.606017 31617 log.cpp:702] Attempting to truncate the log to 1
I0120 02:05:37.606272 31609 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0120 02:05:37.606510 31610 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0120 02:05:37.606606 31612 hierarchical.cpp:172] Skipping recovery of hierarchical allocator: nothing to recover
I0120 02:05:37.607167 31616 replica.cpp:537] Replica received write request for position 2 from (13744)@172.17.0.5:58640
I0120 02:05:37.637485 31616 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 30.255284ms
I0120 02:05:37.637564 31616 replica.cpp:712] Persisted action at 2
I0120 02:05:37.638952 31609 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0120 02:05:37.670987 31609 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 31.961127ms
I0120 02:05:37.671130 31609 leveldb.cpp:399] Deleting ~1 keys from leveldb took 67456ns
I0120 02:05:37.671156 31609 replica.cpp:712] Persisted action at 2
I0120 02:05:37.671190 31609 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0120 02:05:37.677949 31583 scheduler.cpp:154] Version: 0.27.0
I0120 02:05:37.678800 31602 scheduler.cpp:236] New master detected at master@172.17.0.5:58640
I0120 02:05:37.680143 31614 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:58640
I0120 02:05:37.682929 31614 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0120 02:05:37.683603 31614 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:38747
I0120 02:05:37.684121 31614 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0120 02:05:37.684209 31614 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0120 02:05:37.684775 31613 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0120 02:05:37.685876 31614 hierarchical.cpp:266] Added framework f046bd42-2067-445d-87bf-28de6dfa967e-0000
I0120 02:05:37.686426 31604 master.hpp:1658] Sending heartbeat to f046bd42-2067-445d-87bf-28de6dfa967e-0000
I0120 02:05:37.687696 31617 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:58640
I0120 02:05:37.687867 31614 hierarchical.cpp:1345] No resources available to allocate!
I0120 02:05:37.687909 31614 hierarchical.cpp:1439] No inverse offers to send out!
I0120 02:05:37.687938 31614 hierarchical.cpp:1086] Performed allocation for 0 slaves in 2.034312ms
I0120 02:05:37.688199 31617 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:58640
I0120 02:05:37.689038 31617 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0120 02:05:37.689345 31610 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:58640
I0120 02:05:37.692036 31605 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0120 02:05:37.692567 31605 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:38748
I0120 02:05:37.692942 31605 master.cpp:2717] Processing REQUEST call for framework f046bd42-2067-445d-87bf-28de6dfa967e-0000 (default)
I0120 02:05:37.693120 31606 hierarchical.cpp:586] Received resource request from framework f046bd42-2067-445d-87bf-28de6dfa967e-0000
I0120 02:05:37.693542 31605 master.cpp:1025] Master terminating
I0120 02:05:37.693788 31608 hierarchical.cpp:327] Removed framework f046bd42-2067-445d-87bf-28de6dfa967e-0000
E0120 02:05:37.694896 31609 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (511 ms)
[----------] 22 tests from ContentType/SchedulerTest (16218 ms total)
[----------] Global test environment tear-down
[==========] 930 tests from 123 test cases ran. (710055 ms total)
[ PASSED ] 929 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] MasterTest.MaxCompletedFrameworksFlag
1 FAILED TEST
YOU HAVE 8 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
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-1453252737-25441
Untagged: mesos-1453252737-25441:latest
Deleted: 34548997dfd1cc851c61da39df0a8e2b05f5b6621f0bbed9ff1cd333627d6e80
Deleted: b58a4b5343465f2029127114f5fecc0b497918aaceb8dfc945b495da4d34d305
Deleted: c43eb887b4e509543ed1854723df81e497ba10e3836a23d0daa3726c661a817d
Deleted: a92617c993f7601274797e3619ffb8d093c46aec3a728b456bd68bc0c3bc4487
Deleted: a7e494de9111ffdd5eb7fbbd842a5dc1da53c3b51126c96009859d66e9b782fa
Deleted: 9d970c360787234a98edf6d03ec8bab0ffafc9f49fc23b88666e717a41ad0260
Deleted: 0fcef45cbef20d77e334e80807796007add314609a3420b0c924bc97605cce4f
Deleted: 19453beec6617c5e2463e0c128141a83b14edfb4a07548f739052b3f6b0bd365
Deleted: 52ac6414b282dc8226ab85b3b7444e41e91c3043ae45715488da3f07f359224d
Deleted: 070e4e95bd02949d230ae23eb5ead12d1f6d99d5626f7dc5705a7ce66048095e
Deleted: 0acb5e401fb95e33530b3926e76a98bb28bc84d8c8ad8cf708e601f6a6bebe98
Deleted: a3213f50729e204842132cde5005b01da4734f0cca7099c00f7c6bddfe1e0d84
Deleted: 4f437f87490f4e32f8dd7fd7bda74206e461dd1c1d2009df95febfdd5e9119a7
Deleted: 27aa0eed6522d53b014c75564ea010b5f41329f125bfe4f238dfe6ecb0b9f06e
Build step 'Execute shell' marked build as failure
Re: Build failed in Jenkins: Mesos » gcc,--verbose,ubuntu:14.04,docker||Hadoop #1514
Posted by Vinod Kone <vi...@apache.org>.
This is already being worked on:
https://issues.apache.org/jira/browse/MESOS-4409
On Tue, Jan 19, 2016 at 6:05 PM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:
> See <
> https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1514/changes
> >
>
> Changes:
>
> [vinodkone] Temporarily disabled EventCallFramework test due to MESOS-3273.
>
> ------------------------------------------
> [...truncated 158160 lines...]
> I0120 02:05:36.613643 31613 gc.cpp:54] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_xEfQ9s/slaves/cc1b5682-e8ef-4902-8fca-8988f1c99e7a-S0/frameworks/cc1b5682-e8ef-4902-8fca-8988f1c99e7a-0000/executors/default'
> for gc 6.99999291002074days in the future
> I0120 02:05:36.613736 31613 gc.cpp:54] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_xEfQ9s/slaves/cc1b5682-e8ef-4902-8fca-8988f1c99e7a-S0/frameworks/cc1b5682-e8ef-4902-8fca-8988f1c99e7a-0000'
> for gc 6.9999929082637days in the future
> [ OK ] ContentType/SchedulerTest.Message/1 (595 ms)
> [ RUN ] ContentType/SchedulerTest.Request/0
> I0120 02:05:36.724845 31583 leveldb.cpp:174] Opened db in 98.53574ms
> I0120 02:05:36.758622 31583 leveldb.cpp:181] Compacted db in 33.696595ms
> I0120 02:05:36.758719 31583 leveldb.cpp:196] Created db iterator in 27470ns
> I0120 02:05:36.758739 31583 leveldb.cpp:202] Seeked to beginning of db in
> 3407ns
> I0120 02:05:36.758751 31583 leveldb.cpp:271] Iterated through 0 keys in
> the db in 245ns
> I0120 02:05:36.758806 31583 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0120 02:05:36.759569 31603 recover.cpp:447] Starting replica recovery
> I0120 02:05:36.759866 31603 recover.cpp:473] Replica is in EMPTY status
> I0120 02:05:36.761332 31607 replica.cpp:673] Replica in EMPTY status
> received a broadcasted recover request from (13722)@172.17.0.5:58640
> I0120 02:05:36.762434 31614 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I0120 02:05:36.763751 31606 recover.cpp:564] Updating replica status to
> STARTING
> I0120 02:05:36.766090 31615 master.cpp:374] Master
> cc03c74e-ae61-4cc8-a1de-387aa699cd20 (0d4d8375089a) started on
> 172.17.0.5:58640
> I0120 02:05:36.766131 31615 master.cpp:376] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_http="true"
> --authenticate_slaves="true" --authenticators="crammd5"
> --authorizers="local" --credentials="/tmp/pGEYQi/credentials"
> --framework_sorter="drf" --help="false" --hostname_lookup="true"
> --http_authenticators="basic" --initialize_driver_logging="true"
> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
> --max_slave_ping_timeouts="5" --quiet="false"
> --recovery_slave_removal_limit="100%" --registry="replicated_log"
> --registry_fetch_timeout="1mins" --registry_store_timeout="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/pGEYQi/master" --zk_session_timeout="10secs"
> I0120 02:05:36.766552 31615 master.cpp:423] Master allowing
> unauthenticated frameworks to register
> I0120 02:05:36.766566 31615 master.cpp:426] Master only allowing
> authenticated slaves to register
> I0120 02:05:36.766576 31615 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/pGEYQi/credentials'
> I0120 02:05:36.767047 31615 master.cpp:466] Using default 'crammd5'
> authenticator
> I0120 02:05:36.767241 31615 master.cpp:535] Using default 'basic' HTTP
> authenticator
> I0120 02:05:36.767390 31615 master.cpp:569] Authorization enabled
> I0120 02:05:36.768007 31602 hierarchical.cpp:145] Initialized hierarchical
> allocator process
> I0120 02:05:36.767779 31610 whitelist_watcher.cpp:77] No whitelist given
> I0120 02:05:36.770701 31615 master.cpp:1710] The newly elected leader is
> master@172.17.0.5:58640 with id cc03c74e-ae61-4cc8-a1de-387aa699cd20
> I0120 02:05:36.770858 31615 master.cpp:1723] Elected as the leading master!
> I0120 02:05:36.770998 31615 master.cpp:1468] Recovering from registrar
> I0120 02:05:36.771270 31604 registrar.cpp:307] Recovering registrar
> I0120 02:05:36.801002 31606 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 36.90598ms
> I0120 02:05:36.801110 31606 replica.cpp:320] Persisted replica status to
> STARTING
> I0120 02:05:36.801597 31615 recover.cpp:473] Replica is in STARTING status
> I0120 02:05:36.802916 31606 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (13724)@172.17.0.5:58640
> I0120 02:05:36.803705 31615 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0120 02:05:36.804419 31608 recover.cpp:564] Updating replica status to
> VOTING
> I0120 02:05:36.834411 31602 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 29.838355ms
> I0120 02:05:36.834487 31602 replica.cpp:320] Persisted replica status to
> VOTING
> I0120 02:05:36.834717 31607 recover.cpp:578] Successfully joined the Paxos
> group
> I0120 02:05:36.834997 31607 recover.cpp:462] Recover process terminated
> I0120 02:05:36.835764 31616 log.cpp:659] Attempting to start the writer
> I0120 02:05:36.837440 31611 replica.cpp:493] Replica received implicit
> promise request from (13725)@172.17.0.5:58640 with proposal 1
> I0120 02:05:36.859557 31611 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 22.056591ms
> I0120 02:05:36.859642 31611 replica.cpp:342] Persisted promised to 1
> I0120 02:05:36.860484 31607 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0120 02:05:36.861753 31608 replica.cpp:388] Replica received explicit
> promise request from (13726)@172.17.0.5:58640 for position 0 with
> proposal 2
> I0120 02:05:36.884680 31608 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 22.85458ms
> I0120 02:05:36.884757 31608 replica.cpp:712] Persisted action at 0
> I0120 02:05:36.886225 31607 replica.cpp:537] Replica received write
> request for position 0 from (13727)@172.17.0.5:58640
> I0120 02:05:36.886345 31607 leveldb.cpp:436] Reading position from leveldb
> took 53484ns
> I0120 02:05:36.939693 31607 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 53.275877ms
> I0120 02:05:36.939785 31607 replica.cpp:712] Persisted action at 0
> I0120 02:05:36.940711 31615 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0120 02:05:37.006469 31615 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 65.679436ms
> I0120 02:05:37.006553 31615 replica.cpp:712] Persisted action at 0
> I0120 02:05:37.006592 31615 replica.cpp:697] Replica learned NOP action at
> position 0
> I0120 02:05:37.007726 31603 log.cpp:675] Writer started with ending
> position 0
> I0120 02:05:37.009013 31617 leveldb.cpp:436] Reading position from leveldb
> took 80236ns
> I0120 02:05:37.010120 31605 registrar.cpp:340] Successfully fetched the
> registry (0B) in 238.779904ms
> I0120 02:05:37.010267 31605 registrar.cpp:439] Applied 1 operations in
> 36262ns; attempting to update the 'registry'
> I0120 02:05:37.011092 31609 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0120 02:05:37.011240 31614 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0120 02:05:37.012075 31609 replica.cpp:537] Replica received write
> request for position 1 from (13728)@172.17.0.5:58640
> I0120 02:05:37.064991 31609 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 52.834912ms
> I0120 02:05:37.065095 31609 replica.cpp:712] Persisted action at 1
> I0120 02:05:37.066750 31612 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0120 02:05:37.093667 31612 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 26.849586ms
> I0120 02:05:37.093777 31612 replica.cpp:712] Persisted action at 1
> I0120 02:05:37.093819 31612 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0120 02:05:37.096192 31612 registrar.cpp:484] Successfully updated the
> 'registry' in 85.858816ms
> I0120 02:05:37.096344 31612 registrar.cpp:370] Successfully recovered
> registrar
> I0120 02:05:37.096621 31612 log.cpp:702] Attempting to truncate the log to
> 1
> I0120 02:05:37.097081 31612 master.cpp:1520] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0120 02:05:37.097179 31612 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0120 02:05:37.097612 31612 hierarchical.cpp:172] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0120 02:05:37.098726 31614 replica.cpp:537] Replica received write
> request for position 2 from (13729)@172.17.0.5:58640
> I0120 02:05:37.118737 31614 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 19.945665ms
> I0120 02:05:37.118826 31614 replica.cpp:712] Persisted action at 2
> I0120 02:05:37.119779 31611 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> 2016-01-20
> 02:05:37,144:31583(0x2b14c4401700):ZOO_ERROR@handle_socket_error_msg@1697:
> Socket [127.0.0.1:41699] zk retcode=-4, errno=111(Connection refused):
> server refused to accept the client
> I0120 02:05:37.157114 31611 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 37.268871ms
> I0120 02:05:37.157290 31611 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 84301ns
> I0120 02:05:37.157320 31611 replica.cpp:712] Persisted action at 2
> I0120 02:05:37.157359 31611 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0120 02:05:37.159231 31583 scheduler.cpp:154] Version: 0.27.0
> I0120 02:05:37.160296 31612 scheduler.cpp:236] New master detected at
> master@172.17.0.5:58640
> I0120 02:05:37.161638 31612 scheduler.cpp:298] Sending SUBSCRIBE call to
> master@172.17.0.5:58640
> I0120 02:05:37.164237 31612 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0120 02:05:37.164907 31603 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.5:38745
> I0120 02:05:37.165174 31603 master.cpp:1972] Received subscription
> request for HTTP framework 'default'
> I0120 02:05:37.165251 31603 master.cpp:1749] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0120 02:05:37.165557 31603 master.cpp:2063] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0120 02:05:37.166157 31607 hierarchical.cpp:266] Added framework
> cc03c74e-ae61-4cc8-a1de-387aa699cd20-0000
> I0120 02:05:37.166256 31607 hierarchical.cpp:1345] No resources available
> to allocate!
> I0120 02:05:37.166291 31607 hierarchical.cpp:1439] No inverse offers to
> send out!
> I0120 02:05:37.166318 31607 hierarchical.cpp:1086] Performed allocation
> for 0 slaves in 122939ns
> I0120 02:05:37.166276 31602 master.hpp:1658] Sending heartbeat to
> cc03c74e-ae61-4cc8-a1de-387aa699cd20-0000
> I0120 02:05:37.167464 31607 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> received from master@172.17.0.5:58640
> I0120 02:05:37.168010 31607 scheduler.cpp:457] Enqueuing event HEARTBEAT
> received from master@172.17.0.5:58640
> I0120 02:05:37.168733 31607 master_maintenance_tests.cpp:177] Ignoring
> HEARTBEAT event
> I0120 02:05:37.169327 31605 scheduler.cpp:298] Sending REQUEST call to
> master@172.17.0.5:58640
> I0120 02:05:37.172271 31608 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0120 02:05:37.172833 31608 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.5:38746
> I0120 02:05:37.173071 31608 master.cpp:2717] Processing REQUEST call for
> framework cc03c74e-ae61-4cc8-a1de-387aa699cd20-0000 (default)
> I0120 02:05:37.173508 31602 hierarchical.cpp:586] Received resource
> request from framework cc03c74e-ae61-4cc8-a1de-387aa699cd20-0000
> I0120 02:05:37.174892 31583 master.cpp:1025] Master terminating
> I0120 02:05:37.176116 31608 hierarchical.cpp:327] Removed framework
> cc03c74e-ae61-4cc8-a1de-387aa699cd20-0000
> E0120 02:05:37.177567 31603 scheduler.cpp:431] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/0 (565 ms)
> [ RUN ] ContentType/SchedulerTest.Request/1
> I0120 02:05:37.285358 31583 leveldb.cpp:174] Opened db in 94.000521ms
> I0120 02:05:37.319135 31583 leveldb.cpp:181] Compacted db in 33.689831ms
> I0120 02:05:37.319242 31583 leveldb.cpp:196] Created db iterator in 29758ns
> I0120 02:05:37.319262 31583 leveldb.cpp:202] Seeked to beginning of db in
> 4248ns
> I0120 02:05:37.319278 31583 leveldb.cpp:271] Iterated through 0 keys in
> the db in 397ns
> I0120 02:05:37.319335 31583 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0120 02:05:37.319994 31607 recover.cpp:447] Starting replica recovery
> I0120 02:05:37.320310 31607 recover.cpp:473] Replica is in EMPTY status
> I0120 02:05:37.321465 31613 replica.cpp:673] Replica in EMPTY status
> received a broadcasted recover request from (13737)@172.17.0.5:58640
> I0120 02:05:37.321980 31605 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I0120 02:05:37.322468 31616 recover.cpp:564] Updating replica status to
> STARTING
> I0120 02:05:37.324654 31606 master.cpp:374] Master
> f046bd42-2067-445d-87bf-28de6dfa967e (0d4d8375089a) started on
> 172.17.0.5:58640
> I0120 02:05:37.324684 31606 master.cpp:376] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_http="true"
> --authenticate_slaves="true" --authenticators="crammd5"
> --authorizers="local" --credentials="/tmp/IjSltW/credentials"
> --framework_sorter="drf" --help="false" --hostname_lookup="true"
> --http_authenticators="basic" --initialize_driver_logging="true"
> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
> --max_slave_ping_timeouts="5" --quiet="false"
> --recovery_slave_removal_limit="100%" --registry="replicated_log"
> --registry_fetch_timeout="1mins" --registry_store_timeout="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/IjSltW/master" --zk_session_timeout="10secs"
> I0120 02:05:37.325153 31606 master.cpp:423] Master allowing
> unauthenticated frameworks to register
> I0120 02:05:37.325165 31606 master.cpp:426] Master only allowing
> authenticated slaves to register
> I0120 02:05:37.325173 31606 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/IjSltW/credentials'
> I0120 02:05:37.325497 31606 master.cpp:466] Using default 'crammd5'
> authenticator
> I0120 02:05:37.325636 31606 master.cpp:535] Using default 'basic' HTTP
> authenticator
> I0120 02:05:37.325815 31606 master.cpp:569] Authorization enabled
> I0120 02:05:37.326037 31613 whitelist_watcher.cpp:77] No whitelist given
> I0120 02:05:37.326030 31603 hierarchical.cpp:145] Initialized hierarchical
> allocator process
> I0120 02:05:37.327630 31610 master.cpp:1710] The newly elected leader is
> master@172.17.0.5:58640 with id f046bd42-2067-445d-87bf-28de6dfa967e
> I0120 02:05:37.327666 31610 master.cpp:1723] Elected as the leading master!
> I0120 02:05:37.327692 31610 master.cpp:1468] Recovering from registrar
> I0120 02:05:37.327831 31605 registrar.cpp:307] Recovering registrar
> I0120 02:05:37.344106 31602 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 21.471088ms
> I0120 02:05:37.344203 31602 replica.cpp:320] Persisted replica status to
> STARTING
> I0120 02:05:37.344617 31602 recover.cpp:473] Replica is in STARTING status
> I0120 02:05:37.346006 31602 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (13739)@172.17.0.5:58640
> I0120 02:05:37.346552 31602 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0120 02:05:37.347138 31610 recover.cpp:564] Updating replica status to
> VOTING
> I0120 02:05:37.386360 31602 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 39.064601ms
> I0120 02:05:37.386446 31602 replica.cpp:320] Persisted replica status to
> VOTING
> I0120 02:05:37.386718 31602 recover.cpp:578] Successfully joined the Paxos
> group
> I0120 02:05:37.386921 31602 recover.cpp:462] Recover process terminated
> I0120 02:05:37.387526 31610 log.cpp:659] Attempting to start the writer
> I0120 02:05:37.388918 31610 replica.cpp:493] Replica received implicit
> promise request from (13740)@172.17.0.5:58640 with proposal 1
> I0120 02:05:37.428285 31610 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 39.318601ms
> I0120 02:05:37.428359 31610 replica.cpp:342] Persisted promised to 1
> I0120 02:05:37.429132 31602 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0120 02:05:37.430405 31615 replica.cpp:388] Replica received explicit
> promise request from (13741)@172.17.0.5:58640 for position 0 with
> proposal 2
> I0120 02:05:37.466537 31615 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 36.076479ms
> I0120 02:05:37.466617 31615 replica.cpp:712] Persisted action at 0
> I0120 02:05:37.468135 31606 replica.cpp:537] Replica received write
> request for position 0 from (13742)@172.17.0.5:58640
> I0120 02:05:37.468216 31606 leveldb.cpp:436] Reading position from leveldb
> took 42858ns
> I0120 02:05:37.500077 31606 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 31.79523ms
> I0120 02:05:37.500160 31606 replica.cpp:712] Persisted action at 0
> I0120 02:05:37.501258 31606 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0120 02:05:37.533690 31606 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 32.37603ms
> I0120 02:05:37.533774 31606 replica.cpp:712] Persisted action at 0
> I0120 02:05:37.533808 31606 replica.cpp:697] Replica learned NOP action at
> position 0
> I0120 02:05:37.535087 31616 log.cpp:675] Writer started with ending
> position 0
> I0120 02:05:37.536653 31616 leveldb.cpp:436] Reading position from leveldb
> took 52048ns
> I0120 02:05:37.537794 31609 registrar.cpp:340] Successfully fetched the
> registry (0B) in 209.910016ms
> I0120 02:05:37.537935 31609 registrar.cpp:439] Applied 1 operations in
> 39020ns; attempting to update the 'registry'
> I0120 02:05:37.538696 31609 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0120 02:05:37.538849 31615 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0120 02:05:37.539626 31608 replica.cpp:537] Replica received write
> request for position 1 from (13743)@172.17.0.5:58640
> I0120 02:05:37.570647 31608 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 30.954831ms
> I0120 02:05:37.570721 31608 replica.cpp:712] Persisted action at 1
> I0120 02:05:37.571758 31607 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0120 02:05:37.604235 31607 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 32.428004ms
> I0120 02:05:37.604311 31607 replica.cpp:712] Persisted action at 1
> I0120 02:05:37.604341 31607 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0120 02:05:37.605705 31604 registrar.cpp:484] Successfully updated the
> 'registry' in 67.686912ms
> I0120 02:05:37.605860 31604 registrar.cpp:370] Successfully recovered
> registrar
> I0120 02:05:37.606017 31617 log.cpp:702] Attempting to truncate the log to
> 1
> I0120 02:05:37.606272 31609 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0120 02:05:37.606510 31610 master.cpp:1520] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0120 02:05:37.606606 31612 hierarchical.cpp:172] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0120 02:05:37.607167 31616 replica.cpp:537] Replica received write
> request for position 2 from (13744)@172.17.0.5:58640
> I0120 02:05:37.637485 31616 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 30.255284ms
> I0120 02:05:37.637564 31616 replica.cpp:712] Persisted action at 2
> I0120 02:05:37.638952 31609 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I0120 02:05:37.670987 31609 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 31.961127ms
> I0120 02:05:37.671130 31609 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 67456ns
> I0120 02:05:37.671156 31609 replica.cpp:712] Persisted action at 2
> I0120 02:05:37.671190 31609 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0120 02:05:37.677949 31583 scheduler.cpp:154] Version: 0.27.0
> I0120 02:05:37.678800 31602 scheduler.cpp:236] New master detected at
> master@172.17.0.5:58640
> I0120 02:05:37.680143 31614 scheduler.cpp:298] Sending SUBSCRIBE call to
> master@172.17.0.5:58640
> I0120 02:05:37.682929 31614 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0120 02:05:37.683603 31614 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.5:38747
> I0120 02:05:37.684121 31614 master.cpp:1972] Received subscription request
> for HTTP framework 'default'
> I0120 02:05:37.684209 31614 master.cpp:1749] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0120 02:05:37.684775 31613 master.cpp:2063] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0120 02:05:37.685876 31614 hierarchical.cpp:266] Added framework
> f046bd42-2067-445d-87bf-28de6dfa967e-0000
> I0120 02:05:37.686426 31604 master.hpp:1658] Sending heartbeat to
> f046bd42-2067-445d-87bf-28de6dfa967e-0000
> I0120 02:05:37.687696 31617 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> received from master@172.17.0.5:58640
> I0120 02:05:37.687867 31614 hierarchical.cpp:1345] No resources available
> to allocate!
> I0120 02:05:37.687909 31614 hierarchical.cpp:1439] No inverse offers to
> send out!
> I0120 02:05:37.687938 31614 hierarchical.cpp:1086] Performed allocation
> for 0 slaves in 2.034312ms
> I0120 02:05:37.688199 31617 scheduler.cpp:457] Enqueuing event HEARTBEAT
> received from master@172.17.0.5:58640
> I0120 02:05:37.689038 31617 master_maintenance_tests.cpp:177] Ignoring
> HEARTBEAT event
> I0120 02:05:37.689345 31610 scheduler.cpp:298] Sending REQUEST call to
> master@172.17.0.5:58640
> I0120 02:05:37.692036 31605 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0120 02:05:37.692567 31605 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.5:38748
> I0120 02:05:37.692942 31605 master.cpp:2717] Processing REQUEST call for
> framework f046bd42-2067-445d-87bf-28de6dfa967e-0000 (default)
> I0120 02:05:37.693120 31606 hierarchical.cpp:586] Received resource
> request from framework f046bd42-2067-445d-87bf-28de6dfa967e-0000
> I0120 02:05:37.693542 31605 master.cpp:1025] Master terminating
> I0120 02:05:37.693788 31608 hierarchical.cpp:327] Removed framework
> f046bd42-2067-445d-87bf-28de6dfa967e-0000
> E0120 02:05:37.694896 31609 scheduler.cpp:431] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/1 (511 ms)
> [----------] 22 tests from ContentType/SchedulerTest (16218 ms total)
>
> [----------] Global test environment tear-down
> [==========] 930 tests from 123 test cases ran. (710055 ms total)
> [ PASSED ] 929 tests.
> [ FAILED ] 1 test, listed below:
> [ FAILED ] MasterTest.MaxCompletedFrameworksFlag
>
> 1 FAILED TEST
> YOU HAVE 8 DISABLED TESTS
>
> make[4]: *** [check-local] Error 1
> make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> make[3]: *** [check-am] Error 2
> make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> 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-1453252737-25441
> Untagged: mesos-1453252737-25441:latest
> Deleted: 34548997dfd1cc851c61da39df0a8e2b05f5b6621f0bbed9ff1cd333627d6e80
> Deleted: b58a4b5343465f2029127114f5fecc0b497918aaceb8dfc945b495da4d34d305
> Deleted: c43eb887b4e509543ed1854723df81e497ba10e3836a23d0daa3726c661a817d
> Deleted: a92617c993f7601274797e3619ffb8d093c46aec3a728b456bd68bc0c3bc4487
> Deleted: a7e494de9111ffdd5eb7fbbd842a5dc1da53c3b51126c96009859d66e9b782fa
> Deleted: 9d970c360787234a98edf6d03ec8bab0ffafc9f49fc23b88666e717a41ad0260
> Deleted: 0fcef45cbef20d77e334e80807796007add314609a3420b0c924bc97605cce4f
> Deleted: 19453beec6617c5e2463e0c128141a83b14edfb4a07548f739052b3f6b0bd365
> Deleted: 52ac6414b282dc8226ab85b3b7444e41e91c3043ae45715488da3f07f359224d
> Deleted: 070e4e95bd02949d230ae23eb5ead12d1f6d99d5626f7dc5705a7ce66048095e
> Deleted: 0acb5e401fb95e33530b3926e76a98bb28bc84d8c8ad8cf708e601f6a6bebe98
> Deleted: a3213f50729e204842132cde5005b01da4734f0cca7099c00f7c6bddfe1e0d84
> Deleted: 4f437f87490f4e32f8dd7fd7bda74206e461dd1c1d2009df95febfdd5e9119a7
> Deleted: 27aa0eed6522d53b014c75564ea010b5f41329f125bfe4f238dfe6ecb0b9f06e
> Build step 'Execute shell' marked build as failure
>
Jenkins build is back to normal : Mesos » gcc,--verbose,ubuntu:14.04,docker||Hadoop #1515
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1515/>