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/19 07:07:31 UTC
Build failed in Jenkins: mesos-reviewbot #10915
See <https://builds.apache.org/job/mesos-reviewbot/10915/>
------------------------------------------
[...truncated 165577 lines...]
I0119 06:07:22.438992 31580 leveldb.cpp:202] Seeked to beginning of db in 3444ns
I0119 06:07:22.439004 31580 leveldb.cpp:271] Iterated through 0 keys in the db in 221ns
I0119 06:07:22.439055 31580 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0119 06:07:22.440347 31611 recover.cpp:447] Starting replica recovery
I0119 06:07:22.440608 31611 recover.cpp:473] Replica is in EMPTY status
I0119 06:07:22.441998 31607 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13710)@172.17.0.2:50563
I0119 06:07:22.444185 31611 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0119 06:07:22.444748 31611 recover.cpp:564] Updating replica status to STARTING
I0119 06:07:22.447232 31606 master.cpp:374] Master 113429e2-bbb5-4f52-b71b-88502b457830 (24b48acd5f4f) started on 172.17.0.2:50563
I0119 06:07:22.447299 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/vk4frQ/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/vk4frQ/master" --zk_session_timeout="10secs"
I0119 06:07:22.447675 31606 master.cpp:423] Master allowing unauthenticated frameworks to register
I0119 06:07:22.447688 31606 master.cpp:426] Master only allowing authenticated slaves to register
I0119 06:07:22.447696 31606 credentials.hpp:35] Loading credentials for authentication from '/tmp/vk4frQ/credentials'
I0119 06:07:22.447854 31611 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 940146ns
I0119 06:07:22.447881 31611 replica.cpp:320] Persisted replica status to STARTING
I0119 06:07:22.448099 31611 recover.cpp:473] Replica is in STARTING status
I0119 06:07:22.449793 31611 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13711)@172.17.0.2:50563
I0119 06:07:22.451160 31611 recover.cpp:193] Received a recover response from a replica in STARTING status
I0119 06:07:22.451758 31611 recover.cpp:564] Updating replica status to VOTING
I0119 06:07:22.452852 31611 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 889927ns
I0119 06:07:22.452880 31611 replica.cpp:320] Persisted replica status to VOTING
I0119 06:07:22.453245 31606 master.cpp:466] Using default 'crammd5' authenticator
I0119 06:07:22.453393 31606 master.cpp:535] Using default 'basic' HTTP authenticator
I0119 06:07:22.453507 31606 master.cpp:569] Authorization enabled
I0119 06:07:22.455849 31611 recover.cpp:578] Successfully joined the Paxos group
I0119 06:07:22.456018 31611 recover.cpp:462] Recover process terminated
I0119 06:07:22.456104 31611 whitelist_watcher.cpp:77] No whitelist given
I0119 06:07:22.455811 31607 hierarchical.cpp:145] Initialized hierarchical allocator process
I0119 06:07:22.458767 31602 master.cpp:1710] The newly elected leader is master@172.17.0.2:50563 with id 113429e2-bbb5-4f52-b71b-88502b457830
I0119 06:07:22.458807 31602 master.cpp:1723] Elected as the leading master!
I0119 06:07:22.458843 31602 master.cpp:1468] Recovering from registrar
I0119 06:07:22.459000 31599 registrar.cpp:307] Recovering registrar
I0119 06:07:22.461292 31610 log.cpp:659] Attempting to start the writer
I0119 06:07:22.462478 31611 replica.cpp:493] Replica received implicit promise request from (13713)@172.17.0.2:50563 with proposal 1
I0119 06:07:22.463049 31611 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 535569ns
I0119 06:07:22.463073 31611 replica.cpp:342] Persisted promised to 1
I0119 06:07:22.463904 31604 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0119 06:07:22.465014 31607 replica.cpp:388] Replica received explicit promise request from (13714)@172.17.0.2:50563 for position 0 with proposal 2
I0119 06:07:22.465450 31607 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 393986ns
I0119 06:07:22.465474 31607 replica.cpp:712] Persisted action at 0
I0119 06:07:22.467000 31611 replica.cpp:537] Replica received write request for position 0 from (13715)@172.17.0.2:50563
I0119 06:07:22.467074 31611 leveldb.cpp:436] Reading position from leveldb took 34937ns
I0119 06:07:22.467538 31611 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 410644ns
I0119 06:07:22.467569 31611 replica.cpp:712] Persisted action at 0
I0119 06:07:22.468147 31604 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0119 06:07:22.468515 31604 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 335768ns
I0119 06:07:22.468540 31604 replica.cpp:712] Persisted action at 0
I0119 06:07:22.468564 31604 replica.cpp:697] Replica learned NOP action at position 0
I0119 06:07:22.469283 31609 log.cpp:675] Writer started with ending position 0
I0119 06:07:22.470495 31614 leveldb.cpp:436] Reading position from leveldb took 34326ns
I0119 06:07:22.471745 31605 registrar.cpp:340] Successfully fetched the registry (0B) in 12.67584ms
I0119 06:07:22.471904 31605 registrar.cpp:439] Applied 1 operations in 40089ns; attempting to update the 'registry'
I0119 06:07:22.472620 31604 log.cpp:683] Attempting to append 170 bytes to the log
I0119 06:07:22.472780 31601 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0119 06:07:22.473675 31604 replica.cpp:537] Replica received write request for position 1 from (13716)@172.17.0.2:50563
I0119 06:07:22.474210 31604 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 484894ns
I0119 06:07:22.474319 31604 replica.cpp:712] Persisted action at 1
I0119 06:07:22.475239 31604 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0119 06:07:22.475656 31604 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 388237ns
I0119 06:07:22.475692 31604 replica.cpp:712] Persisted action at 1
I0119 06:07:22.475721 31604 replica.cpp:697] Replica learned APPEND action at position 1
I0119 06:07:22.477617 31611 registrar.cpp:484] Successfully updated the 'registry' in 5.616896ms
I0119 06:07:22.477843 31611 registrar.cpp:370] Successfully recovered registrar
I0119 06:07:22.478154 31611 log.cpp:702] Attempting to truncate the log to 1
I0119 06:07:22.478641 31611 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0119 06:07:22.478750 31611 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0119 06:07:22.478915 31600 hierarchical.cpp:172] Skipping recovery of hierarchical allocator: nothing to recover
I0119 06:07:22.480073 31604 replica.cpp:537] Replica received write request for position 2 from (13717)@172.17.0.2:50563
I0119 06:07:22.480618 31604 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 503515ns
I0119 06:07:22.480648 31604 replica.cpp:712] Persisted action at 2
I0119 06:07:22.482221 31606 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0119 06:07:22.482606 31606 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 348429ns
I0119 06:07:22.482666 31606 leveldb.cpp:399] Deleting ~1 keys from leveldb took 32770ns
I0119 06:07:22.482689 31606 replica.cpp:712] Persisted action at 2
I0119 06:07:22.482717 31606 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0119 06:07:22.489920 31580 scheduler.cpp:154] Version: 0.27.0
I0119 06:07:22.491029 31607 scheduler.cpp:236] New master detected at master@172.17.0.2:50563
I0119 06:07:22.493018 31604 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:50563
I0119 06:07:22.495082 31604 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0119 06:07:22.495555 31604 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:60304
I0119 06:07:22.495743 31604 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0119 06:07:22.495827 31604 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0119 06:07:22.496436 31604 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0119 06:07:22.497040 31604 hierarchical.cpp:266] Added framework 113429e2-bbb5-4f52-b71b-88502b457830-0000
I0119 06:07:22.497112 31604 hierarchical.cpp:1338] No resources available to allocate!
I0119 06:07:22.497153 31604 hierarchical.cpp:1432] No inverse offers to send out!
I0119 06:07:22.497184 31604 hierarchical.cpp:1086] Performed allocation for 0 slaves in 115936ns
I0119 06:07:22.497859 31599 master.hpp:1665] Sending heartbeat to 113429e2-bbb5-4f52-b71b-88502b457830-0000
I0119 06:07:22.498435 31604 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:50563
I0119 06:07:22.499595 31600 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:50563
I0119 06:07:22.500218 31603 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0119 06:07:22.500247 31600 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:50563
I0119 06:07:22.501874 31610 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0119 06:07:22.502527 31608 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:60305
I0119 06:07:22.502655 31608 master.cpp:2717] Processing REQUEST call for framework 113429e2-bbb5-4f52-b71b-88502b457830-0000 (default)
I0119 06:07:22.502949 31612 hierarchical.cpp:586] Received resource request from framework 113429e2-bbb5-4f52-b71b-88502b457830-0000
I0119 06:07:22.503617 31580 master.cpp:1025] Master terminating
I0119 06:07:22.503871 31602 hierarchical.cpp:327] Removed framework 113429e2-bbb5-4f52-b71b-88502b457830-0000
E0119 06:07:22.506150 31604 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (87 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0119 06:07:22.515035 31580 leveldb.cpp:174] Opened db in 2.29443ms
I0119 06:07:22.516018 31580 leveldb.cpp:181] Compacted db in 939488ns
I0119 06:07:22.516067 31580 leveldb.cpp:196] Created db iterator in 22105ns
I0119 06:07:22.516194 31580 leveldb.cpp:202] Seeked to beginning of db in 2785ns
I0119 06:07:22.516217 31580 leveldb.cpp:271] Iterated through 0 keys in the db in 388ns
I0119 06:07:22.516271 31580 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0119 06:07:22.517076 31602 recover.cpp:447] Starting replica recovery
I0119 06:07:22.517356 31604 recover.cpp:473] Replica is in EMPTY status
I0119 06:07:22.518417 31614 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13725)@172.17.0.2:50563
I0119 06:07:22.520074 31604 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0119 06:07:22.520494 31614 recover.cpp:564] Updating replica status to STARTING
I0119 06:07:22.521368 31604 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 679508ns
I0119 06:07:22.521473 31604 replica.cpp:320] Persisted replica status to STARTING
I0119 06:07:22.521842 31604 recover.cpp:473] Replica is in STARTING status
I0119 06:07:22.523095 31600 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13726)@172.17.0.2:50563
I0119 06:07:22.523529 31599 master.cpp:374] Master d05024a4-6c5a-4ad0-bb23-933861fdd252 (24b48acd5f4f) started on 172.17.0.2:50563
I0119 06:07:22.523524 31612 recover.cpp:193] Received a recover response from a replica in STARTING status
I0119 06:07:22.524134 31604 recover.cpp:564] Updating replica status to VOTING
I0119 06:07:22.523638 31599 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/eWb4NB/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/eWb4NB/master" --zk_session_timeout="10secs"
I0119 06:07:22.524232 31599 master.cpp:423] Master allowing unauthenticated frameworks to register
I0119 06:07:22.524248 31599 master.cpp:426] Master only allowing authenticated slaves to register
I0119 06:07:22.524258 31599 credentials.hpp:35] Loading credentials for authentication from '/tmp/eWb4NB/credentials'
I0119 06:07:22.524638 31599 master.cpp:466] Using default 'crammd5' authenticator
I0119 06:07:22.524895 31599 master.cpp:535] Using default 'basic' HTTP authenticator
I0119 06:07:22.524976 31604 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 416302ns
I0119 06:07:22.524999 31604 replica.cpp:320] Persisted replica status to VOTING
I0119 06:07:22.525140 31601 recover.cpp:578] Successfully joined the Paxos group
I0119 06:07:22.525351 31599 master.cpp:569] Authorization enabled
I0119 06:07:22.525450 31601 recover.cpp:462] Recover process terminated
I0119 06:07:22.525640 31602 hierarchical.cpp:145] Initialized hierarchical allocator process
I0119 06:07:22.525704 31601 whitelist_watcher.cpp:77] No whitelist given
I0119 06:07:22.527844 31602 master.cpp:1710] The newly elected leader is master@172.17.0.2:50563 with id d05024a4-6c5a-4ad0-bb23-933861fdd252
I0119 06:07:22.527883 31602 master.cpp:1723] Elected as the leading master!
I0119 06:07:22.527904 31602 master.cpp:1468] Recovering from registrar
I0119 06:07:22.528058 31614 registrar.cpp:307] Recovering registrar
I0119 06:07:22.528677 31608 log.cpp:659] Attempting to start the writer
I0119 06:07:22.529742 31608 replica.cpp:493] Replica received implicit promise request from (13728)@172.17.0.2:50563 with proposal 1
I0119 06:07:22.530339 31608 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 567072ns
I0119 06:07:22.530361 31608 replica.cpp:342] Persisted promised to 1
I0119 06:07:22.531023 31606 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0119 06:07:22.532183 31599 replica.cpp:388] Replica received explicit promise request from (13729)@172.17.0.2:50563 for position 0 with proposal 2
I0119 06:07:22.532585 31599 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 356039ns
I0119 06:07:22.532608 31599 replica.cpp:712] Persisted action at 0
I0119 06:07:22.533730 31613 replica.cpp:537] Replica received write request for position 0 from (13730)@172.17.0.2:50563
I0119 06:07:22.533804 31613 leveldb.cpp:436] Reading position from leveldb took 43284ns
I0119 06:07:22.534196 31613 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 331553ns
I0119 06:07:22.534217 31613 replica.cpp:712] Persisted action at 0
I0119 06:07:22.534806 31613 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0119 06:07:22.535464 31613 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 381591ns
I0119 06:07:22.535491 31613 replica.cpp:712] Persisted action at 0
I0119 06:07:22.535513 31613 replica.cpp:697] Replica learned NOP action at position 0
I0119 06:07:22.536450 31599 log.cpp:675] Writer started with ending position 0
I0119 06:07:22.537516 31614 leveldb.cpp:436] Reading position from leveldb took 32071ns
I0119 06:07:22.538547 31609 registrar.cpp:340] Successfully fetched the registry (0B) in 10.44608ms
I0119 06:07:22.538679 31609 registrar.cpp:439] Applied 1 operations in 38504ns; attempting to update the 'registry'
I0119 06:07:22.539510 31609 log.cpp:683] Attempting to append 170 bytes to the log
I0119 06:07:22.539620 31610 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0119 06:07:22.541509 31610 replica.cpp:537] Replica received write request for position 1 from (13731)@172.17.0.2:50563
I0119 06:07:22.542070 31610 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 516973ns
I0119 06:07:22.542100 31610 replica.cpp:712] Persisted action at 1
I0119 06:07:22.542985 31613 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0119 06:07:22.543472 31613 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 435193ns
I0119 06:07:22.543506 31613 replica.cpp:712] Persisted action at 1
I0119 06:07:22.543534 31613 replica.cpp:697] Replica learned APPEND action at position 1
I0119 06:07:22.544585 31602 registrar.cpp:484] Successfully updated the 'registry' in 5.748224ms
I0119 06:07:22.544742 31602 registrar.cpp:370] Successfully recovered registrar
I0119 06:07:22.544859 31600 log.cpp:702] Attempting to truncate the log to 1
I0119 06:07:22.545083 31602 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0119 06:07:22.545382 31600 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0119 06:07:22.545490 31602 hierarchical.cpp:172] Skipping recovery of hierarchical allocator: nothing to recover
I0119 06:07:22.546223 31599 replica.cpp:537] Replica received write request for position 2 from (13732)@172.17.0.2:50563
I0119 06:07:22.546743 31599 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 475650ns
I0119 06:07:22.546774 31599 replica.cpp:712] Persisted action at 2
I0119 06:07:22.547472 31613 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0119 06:07:22.548056 31613 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 554245ns
I0119 06:07:22.548159 31613 leveldb.cpp:399] Deleting ~1 keys from leveldb took 77888ns
I0119 06:07:22.548183 31613 replica.cpp:712] Persisted action at 2
I0119 06:07:22.548267 31613 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0119 06:07:22.556499 31580 scheduler.cpp:154] Version: 0.27.0
I0119 06:07:22.557257 31609 scheduler.cpp:236] New master detected at master@172.17.0.2:50563
I0119 06:07:22.558471 31602 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:50563
I0119 06:07:22.560677 31601 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0119 06:07:22.561189 31607 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:60306
I0119 06:07:22.561636 31607 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0119 06:07:22.561748 31607 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0119 06:07:22.562307 31606 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0119 06:07:22.564051 31607 hierarchical.cpp:266] Added framework d05024a4-6c5a-4ad0-bb23-933861fdd252-0000
I0119 06:07:22.564422 31607 hierarchical.cpp:1338] No resources available to allocate!
I0119 06:07:22.564728 31607 hierarchical.cpp:1432] No inverse offers to send out!
I0119 06:07:22.565058 31607 hierarchical.cpp:1086] Performed allocation for 0 slaves in 716690ns
I0119 06:07:22.565356 31607 master.hpp:1665] Sending heartbeat to d05024a4-6c5a-4ad0-bb23-933861fdd252-0000
I0119 06:07:22.566895 31607 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:50563
I0119 06:07:22.569545 31610 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:50563
I0119 06:07:22.570375 31610 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:50563
I0119 06:07:22.572010 31610 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0119 06:07:22.573775 31609 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0119 06:07:22.574496 31609 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:60307
I0119 06:07:22.574906 31609 master.cpp:2717] Processing REQUEST call for framework d05024a4-6c5a-4ad0-bb23-933861fdd252-0000 (default)
I0119 06:07:22.575198 31614 hierarchical.cpp:586] Received resource request from framework d05024a4-6c5a-4ad0-bb23-933861fdd252-0000
I0119 06:07:22.576326 31600 master.cpp:1025] Master terminating
I0119 06:07:22.576629 31603 hierarchical.cpp:327] Removed framework d05024a4-6c5a-4ad0-bb23-933861fdd252-0000
E0119 06:07:22.577653 31600 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (72 ms)
[----------] 22 tests from ContentType/SchedulerTest (5103 ms total)
[----------] Global test environment tear-down
[==========] 929 tests from 123 test cases ran. (363507 ms total)
[ PASSED ] 925 tests.
[ FAILED ] 4 tests, listed below:
[ FAILED ] FetcherCacheTest.LocalUncached
[ FAILED ] FetcherCacheTest.RemoveLRUCacheEntries
[ FAILED ] FetcherCacheHttpTest.HttpCachedSerialized
[ FAILED ] SlaveRecoveryTest/0.ShutdownSlave, where TypeParam = mesos::internal::slave::MesosContainerizer
4 FAILED TESTS
YOU HAVE 7 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-1453181562-15918
Untagged: mesos-1453181562-15918:latest
Deleted: d5d15187b8af8b5f466f96a209c4af373406a02d0938a48b169cf2976380537f
Deleted: 298b370834fc713742db11d2be4fe6e34205abb53540824fece15bf8753819b8
Deleted: 5b2eb20272f35fceae8fdce62e4c57c2478419196e74a3a2bc8c6d98a0618ca0
Deleted: 06643ff47c057205519445ceae719571a44fcf5954edb1ef95c35fce16cc1265
Deleted: 01c54e71699d2bc7ca70cb511ef423cc56db6e655c6d2ec71efa338aa6e7b3e8
Deleted: 507e39554170a3cbf0b5fba5456ecaee6db5e24fd25e8d4995698673146e5efa
Deleted: 96a2bb91a832dc44b76166788e027d34a9580fbda947551159744a4c9990b52b
Deleted: 570bf5d82d9c1e1fceedb64f4847b443cdcea88e7eff00d5fc863416c2c08a2f
Deleted: c7dbbed2cc203b0a90465997fc6c11dce9a668d74eba0fb26db0f1e0ca26fe6e
Deleted: 741feff04701ff2eaff61991e8487723bd02323e451802617826872a39cb5906
Deleted: 6f8e12497ca1ae6d36d30dae115ee8c475895f42678b1d50a3aaeaa559db5ba9
Deleted: 1608b25b81da326dff342838b830b408e94133a9dbf71dad68e9209e4299f963
Deleted: 0e465a1a7583370979c9fb1421a284d427288f443061e6bde7fea8fad41854b7
Deleted: 2a6e5a016b8dff4bf0161a7e3ac55391f6fa06a290fadadc7bc2a69ab62b034b
Error handling URL https://reviews.apache.org/api/review-requests/41308/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard e7b4ba423f380113ab1937a3c506d82b3b8169ea
Build step 'Execute shell' marked build as failure
Re: Build failed in Jenkins: mesos-reviewbot #10915
Posted by Vinod Kone <vi...@apache.org>.
Bernd, Jie: Are you looking into these?
On Mon, Jan 18, 2016 at 10:07 PM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:
> See <https://builds.apache.org/job/mesos-reviewbot/10915/>
>
> ------------------------------------------
> [...truncated 165577 lines...]
> I0119 06:07:22.438992 31580 leveldb.cpp:202] Seeked to beginning of db in
> 3444ns
> I0119 06:07:22.439004 31580 leveldb.cpp:271] Iterated through 0 keys in
> the db in 221ns
> I0119 06:07:22.439055 31580 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0119 06:07:22.440347 31611 recover.cpp:447] Starting replica recovery
> I0119 06:07:22.440608 31611 recover.cpp:473] Replica is in EMPTY status
> I0119 06:07:22.441998 31607 replica.cpp:673] Replica in EMPTY status
> received a broadcasted recover request from (13710)@172.17.0.2:50563
> I0119 06:07:22.444185 31611 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I0119 06:07:22.444748 31611 recover.cpp:564] Updating replica status to
> STARTING
> I0119 06:07:22.447232 31606 master.cpp:374] Master
> 113429e2-bbb5-4f52-b71b-88502b457830 (24b48acd5f4f) started on
> 172.17.0.2:50563
> I0119 06:07:22.447299 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/vk4frQ/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/vk4frQ/master" --zk_session_timeout="10secs"
> I0119 06:07:22.447675 31606 master.cpp:423] Master allowing
> unauthenticated frameworks to register
> I0119 06:07:22.447688 31606 master.cpp:426] Master only allowing
> authenticated slaves to register
> I0119 06:07:22.447696 31606 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/vk4frQ/credentials'
> I0119 06:07:22.447854 31611 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 940146ns
> I0119 06:07:22.447881 31611 replica.cpp:320] Persisted replica status to
> STARTING
> I0119 06:07:22.448099 31611 recover.cpp:473] Replica is in STARTING status
> I0119 06:07:22.449793 31611 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (13711)@172.17.0.2:50563
> I0119 06:07:22.451160 31611 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0119 06:07:22.451758 31611 recover.cpp:564] Updating replica status to
> VOTING
> I0119 06:07:22.452852 31611 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 889927ns
> I0119 06:07:22.452880 31611 replica.cpp:320] Persisted replica status to
> VOTING
> I0119 06:07:22.453245 31606 master.cpp:466] Using default 'crammd5'
> authenticator
> I0119 06:07:22.453393 31606 master.cpp:535] Using default 'basic' HTTP
> authenticator
> I0119 06:07:22.453507 31606 master.cpp:569] Authorization enabled
> I0119 06:07:22.455849 31611 recover.cpp:578] Successfully joined the Paxos
> group
> I0119 06:07:22.456018 31611 recover.cpp:462] Recover process terminated
> I0119 06:07:22.456104 31611 whitelist_watcher.cpp:77] No whitelist given
> I0119 06:07:22.455811 31607 hierarchical.cpp:145] Initialized hierarchical
> allocator process
> I0119 06:07:22.458767 31602 master.cpp:1710] The newly elected leader is
> master@172.17.0.2:50563 with id 113429e2-bbb5-4f52-b71b-88502b457830
> I0119 06:07:22.458807 31602 master.cpp:1723] Elected as the leading master!
> I0119 06:07:22.458843 31602 master.cpp:1468] Recovering from registrar
> I0119 06:07:22.459000 31599 registrar.cpp:307] Recovering registrar
> I0119 06:07:22.461292 31610 log.cpp:659] Attempting to start the writer
> I0119 06:07:22.462478 31611 replica.cpp:493] Replica received implicit
> promise request from (13713)@172.17.0.2:50563 with proposal 1
> I0119 06:07:22.463049 31611 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 535569ns
> I0119 06:07:22.463073 31611 replica.cpp:342] Persisted promised to 1
> I0119 06:07:22.463904 31604 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0119 06:07:22.465014 31607 replica.cpp:388] Replica received explicit
> promise request from (13714)@172.17.0.2:50563 for position 0 with
> proposal 2
> I0119 06:07:22.465450 31607 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 393986ns
> I0119 06:07:22.465474 31607 replica.cpp:712] Persisted action at 0
> I0119 06:07:22.467000 31611 replica.cpp:537] Replica received write
> request for position 0 from (13715)@172.17.0.2:50563
> I0119 06:07:22.467074 31611 leveldb.cpp:436] Reading position from leveldb
> took 34937ns
> I0119 06:07:22.467538 31611 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 410644ns
> I0119 06:07:22.467569 31611 replica.cpp:712] Persisted action at 0
> I0119 06:07:22.468147 31604 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0119 06:07:22.468515 31604 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 335768ns
> I0119 06:07:22.468540 31604 replica.cpp:712] Persisted action at 0
> I0119 06:07:22.468564 31604 replica.cpp:697] Replica learned NOP action at
> position 0
> I0119 06:07:22.469283 31609 log.cpp:675] Writer started with ending
> position 0
> I0119 06:07:22.470495 31614 leveldb.cpp:436] Reading position from leveldb
> took 34326ns
> I0119 06:07:22.471745 31605 registrar.cpp:340] Successfully fetched the
> registry (0B) in 12.67584ms
> I0119 06:07:22.471904 31605 registrar.cpp:439] Applied 1 operations in
> 40089ns; attempting to update the 'registry'
> I0119 06:07:22.472620 31604 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0119 06:07:22.472780 31601 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0119 06:07:22.473675 31604 replica.cpp:537] Replica received write
> request for position 1 from (13716)@172.17.0.2:50563
> I0119 06:07:22.474210 31604 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 484894ns
> I0119 06:07:22.474319 31604 replica.cpp:712] Persisted action at 1
> I0119 06:07:22.475239 31604 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0119 06:07:22.475656 31604 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 388237ns
> I0119 06:07:22.475692 31604 replica.cpp:712] Persisted action at 1
> I0119 06:07:22.475721 31604 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0119 06:07:22.477617 31611 registrar.cpp:484] Successfully updated the
> 'registry' in 5.616896ms
> I0119 06:07:22.477843 31611 registrar.cpp:370] Successfully recovered
> registrar
> I0119 06:07:22.478154 31611 log.cpp:702] Attempting to truncate the log to
> 1
> I0119 06:07:22.478641 31611 master.cpp:1520] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0119 06:07:22.478750 31611 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0119 06:07:22.478915 31600 hierarchical.cpp:172] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0119 06:07:22.480073 31604 replica.cpp:537] Replica received write
> request for position 2 from (13717)@172.17.0.2:50563
> I0119 06:07:22.480618 31604 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 503515ns
> I0119 06:07:22.480648 31604 replica.cpp:712] Persisted action at 2
> I0119 06:07:22.482221 31606 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I0119 06:07:22.482606 31606 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 348429ns
> I0119 06:07:22.482666 31606 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 32770ns
> I0119 06:07:22.482689 31606 replica.cpp:712] Persisted action at 2
> I0119 06:07:22.482717 31606 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0119 06:07:22.489920 31580 scheduler.cpp:154] Version: 0.27.0
> I0119 06:07:22.491029 31607 scheduler.cpp:236] New master detected at
> master@172.17.0.2:50563
> I0119 06:07:22.493018 31604 scheduler.cpp:298] Sending SUBSCRIBE call to
> master@172.17.0.2:50563
> I0119 06:07:22.495082 31604 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0119 06:07:22.495555 31604 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.2:60304
> I0119 06:07:22.495743 31604 master.cpp:1972] Received subscription request
> for HTTP framework 'default'
> I0119 06:07:22.495827 31604 master.cpp:1749] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0119 06:07:22.496436 31604 master.cpp:2063] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0119 06:07:22.497040 31604 hierarchical.cpp:266] Added framework
> 113429e2-bbb5-4f52-b71b-88502b457830-0000
> I0119 06:07:22.497112 31604 hierarchical.cpp:1338] No resources available
> to allocate!
> I0119 06:07:22.497153 31604 hierarchical.cpp:1432] No inverse offers to
> send out!
> I0119 06:07:22.497184 31604 hierarchical.cpp:1086] Performed allocation
> for 0 slaves in 115936ns
> I0119 06:07:22.497859 31599 master.hpp:1665] Sending heartbeat to
> 113429e2-bbb5-4f52-b71b-88502b457830-0000
> I0119 06:07:22.498435 31604 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> received from master@172.17.0.2:50563
> I0119 06:07:22.499595 31600 scheduler.cpp:457] Enqueuing event HEARTBEAT
> received from master@172.17.0.2:50563
> I0119 06:07:22.500218 31603 master_maintenance_tests.cpp:177] Ignoring
> HEARTBEAT event
> I0119 06:07:22.500247 31600 scheduler.cpp:298] Sending REQUEST call to
> master@172.17.0.2:50563
> I0119 06:07:22.501874 31610 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0119 06:07:22.502527 31608 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.2:60305
> I0119 06:07:22.502655 31608 master.cpp:2717] Processing REQUEST call for
> framework 113429e2-bbb5-4f52-b71b-88502b457830-0000 (default)
> I0119 06:07:22.502949 31612 hierarchical.cpp:586] Received resource
> request from framework 113429e2-bbb5-4f52-b71b-88502b457830-0000
> I0119 06:07:22.503617 31580 master.cpp:1025] Master terminating
> I0119 06:07:22.503871 31602 hierarchical.cpp:327] Removed framework
> 113429e2-bbb5-4f52-b71b-88502b457830-0000
> E0119 06:07:22.506150 31604 scheduler.cpp:431] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/0 (87 ms)
> [ RUN ] ContentType/SchedulerTest.Request/1
> I0119 06:07:22.515035 31580 leveldb.cpp:174] Opened db in 2.29443ms
> I0119 06:07:22.516018 31580 leveldb.cpp:181] Compacted db in 939488ns
> I0119 06:07:22.516067 31580 leveldb.cpp:196] Created db iterator in 22105ns
> I0119 06:07:22.516194 31580 leveldb.cpp:202] Seeked to beginning of db in
> 2785ns
> I0119 06:07:22.516217 31580 leveldb.cpp:271] Iterated through 0 keys in
> the db in 388ns
> I0119 06:07:22.516271 31580 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0119 06:07:22.517076 31602 recover.cpp:447] Starting replica recovery
> I0119 06:07:22.517356 31604 recover.cpp:473] Replica is in EMPTY status
> I0119 06:07:22.518417 31614 replica.cpp:673] Replica in EMPTY status
> received a broadcasted recover request from (13725)@172.17.0.2:50563
> I0119 06:07:22.520074 31604 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I0119 06:07:22.520494 31614 recover.cpp:564] Updating replica status to
> STARTING
> I0119 06:07:22.521368 31604 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 679508ns
> I0119 06:07:22.521473 31604 replica.cpp:320] Persisted replica status to
> STARTING
> I0119 06:07:22.521842 31604 recover.cpp:473] Replica is in STARTING status
> I0119 06:07:22.523095 31600 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (13726)@172.17.0.2:50563
> I0119 06:07:22.523529 31599 master.cpp:374] Master
> d05024a4-6c5a-4ad0-bb23-933861fdd252 (24b48acd5f4f) started on
> 172.17.0.2:50563
> I0119 06:07:22.523524 31612 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0119 06:07:22.524134 31604 recover.cpp:564] Updating replica status to
> VOTING
> I0119 06:07:22.523638 31599 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/eWb4NB/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/eWb4NB/master" --zk_session_timeout="10secs"
> I0119 06:07:22.524232 31599 master.cpp:423] Master allowing
> unauthenticated frameworks to register
> I0119 06:07:22.524248 31599 master.cpp:426] Master only allowing
> authenticated slaves to register
> I0119 06:07:22.524258 31599 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/eWb4NB/credentials'
> I0119 06:07:22.524638 31599 master.cpp:466] Using default 'crammd5'
> authenticator
> I0119 06:07:22.524895 31599 master.cpp:535] Using default 'basic' HTTP
> authenticator
> I0119 06:07:22.524976 31604 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 416302ns
> I0119 06:07:22.524999 31604 replica.cpp:320] Persisted replica status to
> VOTING
> I0119 06:07:22.525140 31601 recover.cpp:578] Successfully joined the Paxos
> group
> I0119 06:07:22.525351 31599 master.cpp:569] Authorization enabled
> I0119 06:07:22.525450 31601 recover.cpp:462] Recover process terminated
> I0119 06:07:22.525640 31602 hierarchical.cpp:145] Initialized hierarchical
> allocator process
> I0119 06:07:22.525704 31601 whitelist_watcher.cpp:77] No whitelist given
> I0119 06:07:22.527844 31602 master.cpp:1710] The newly elected leader is
> master@172.17.0.2:50563 with id d05024a4-6c5a-4ad0-bb23-933861fdd252
> I0119 06:07:22.527883 31602 master.cpp:1723] Elected as the leading master!
> I0119 06:07:22.527904 31602 master.cpp:1468] Recovering from registrar
> I0119 06:07:22.528058 31614 registrar.cpp:307] Recovering registrar
> I0119 06:07:22.528677 31608 log.cpp:659] Attempting to start the writer
> I0119 06:07:22.529742 31608 replica.cpp:493] Replica received implicit
> promise request from (13728)@172.17.0.2:50563 with proposal 1
> I0119 06:07:22.530339 31608 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 567072ns
> I0119 06:07:22.530361 31608 replica.cpp:342] Persisted promised to 1
> I0119 06:07:22.531023 31606 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0119 06:07:22.532183 31599 replica.cpp:388] Replica received explicit
> promise request from (13729)@172.17.0.2:50563 for position 0 with
> proposal 2
> I0119 06:07:22.532585 31599 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 356039ns
> I0119 06:07:22.532608 31599 replica.cpp:712] Persisted action at 0
> I0119 06:07:22.533730 31613 replica.cpp:537] Replica received write
> request for position 0 from (13730)@172.17.0.2:50563
> I0119 06:07:22.533804 31613 leveldb.cpp:436] Reading position from leveldb
> took 43284ns
> I0119 06:07:22.534196 31613 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 331553ns
> I0119 06:07:22.534217 31613 replica.cpp:712] Persisted action at 0
> I0119 06:07:22.534806 31613 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0119 06:07:22.535464 31613 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 381591ns
> I0119 06:07:22.535491 31613 replica.cpp:712] Persisted action at 0
> I0119 06:07:22.535513 31613 replica.cpp:697] Replica learned NOP action at
> position 0
> I0119 06:07:22.536450 31599 log.cpp:675] Writer started with ending
> position 0
> I0119 06:07:22.537516 31614 leveldb.cpp:436] Reading position from leveldb
> took 32071ns
> I0119 06:07:22.538547 31609 registrar.cpp:340] Successfully fetched the
> registry (0B) in 10.44608ms
> I0119 06:07:22.538679 31609 registrar.cpp:439] Applied 1 operations in
> 38504ns; attempting to update the 'registry'
> I0119 06:07:22.539510 31609 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0119 06:07:22.539620 31610 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0119 06:07:22.541509 31610 replica.cpp:537] Replica received write
> request for position 1 from (13731)@172.17.0.2:50563
> I0119 06:07:22.542070 31610 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 516973ns
> I0119 06:07:22.542100 31610 replica.cpp:712] Persisted action at 1
> I0119 06:07:22.542985 31613 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0119 06:07:22.543472 31613 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 435193ns
> I0119 06:07:22.543506 31613 replica.cpp:712] Persisted action at 1
> I0119 06:07:22.543534 31613 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0119 06:07:22.544585 31602 registrar.cpp:484] Successfully updated the
> 'registry' in 5.748224ms
> I0119 06:07:22.544742 31602 registrar.cpp:370] Successfully recovered
> registrar
> I0119 06:07:22.544859 31600 log.cpp:702] Attempting to truncate the log to
> 1
> I0119 06:07:22.545083 31602 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0119 06:07:22.545382 31600 master.cpp:1520] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0119 06:07:22.545490 31602 hierarchical.cpp:172] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0119 06:07:22.546223 31599 replica.cpp:537] Replica received write
> request for position 2 from (13732)@172.17.0.2:50563
> I0119 06:07:22.546743 31599 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 475650ns
> I0119 06:07:22.546774 31599 replica.cpp:712] Persisted action at 2
> I0119 06:07:22.547472 31613 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I0119 06:07:22.548056 31613 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 554245ns
> I0119 06:07:22.548159 31613 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 77888ns
> I0119 06:07:22.548183 31613 replica.cpp:712] Persisted action at 2
> I0119 06:07:22.548267 31613 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0119 06:07:22.556499 31580 scheduler.cpp:154] Version: 0.27.0
> I0119 06:07:22.557257 31609 scheduler.cpp:236] New master detected at
> master@172.17.0.2:50563
> I0119 06:07:22.558471 31602 scheduler.cpp:298] Sending SUBSCRIBE call to
> master@172.17.0.2:50563
> I0119 06:07:22.560677 31601 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0119 06:07:22.561189 31607 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.2:60306
> I0119 06:07:22.561636 31607 master.cpp:1972] Received subscription request
> for HTTP framework 'default'
> I0119 06:07:22.561748 31607 master.cpp:1749] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0119 06:07:22.562307 31606 master.cpp:2063] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0119 06:07:22.564051 31607 hierarchical.cpp:266] Added framework
> d05024a4-6c5a-4ad0-bb23-933861fdd252-0000
> I0119 06:07:22.564422 31607 hierarchical.cpp:1338] No resources available
> to allocate!
> I0119 06:07:22.564728 31607 hierarchical.cpp:1432] No inverse offers to
> send out!
> I0119 06:07:22.565058 31607 hierarchical.cpp:1086] Performed allocation
> for 0 slaves in 716690ns
> I0119 06:07:22.565356 31607 master.hpp:1665] Sending heartbeat to
> d05024a4-6c5a-4ad0-bb23-933861fdd252-0000
> I0119 06:07:22.566895 31607 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> received from master@172.17.0.2:50563
> I0119 06:07:22.569545 31610 scheduler.cpp:457] Enqueuing event HEARTBEAT
> received from master@172.17.0.2:50563
> I0119 06:07:22.570375 31610 scheduler.cpp:298] Sending REQUEST call to
> master@172.17.0.2:50563
> I0119 06:07:22.572010 31610 master_maintenance_tests.cpp:177] Ignoring
> HEARTBEAT event
> I0119 06:07:22.573775 31609 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0119 06:07:22.574496 31609 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.2:60307
> I0119 06:07:22.574906 31609 master.cpp:2717] Processing REQUEST call for
> framework d05024a4-6c5a-4ad0-bb23-933861fdd252-0000 (default)
> I0119 06:07:22.575198 31614 hierarchical.cpp:586] Received resource
> request from framework d05024a4-6c5a-4ad0-bb23-933861fdd252-0000
> I0119 06:07:22.576326 31600 master.cpp:1025] Master terminating
> I0119 06:07:22.576629 31603 hierarchical.cpp:327] Removed framework
> d05024a4-6c5a-4ad0-bb23-933861fdd252-0000
> E0119 06:07:22.577653 31600 scheduler.cpp:431] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/1 (72 ms)
> [----------] 22 tests from ContentType/SchedulerTest (5103 ms total)
>
> [----------] Global test environment tear-down
> [==========] 929 tests from 123 test cases ran. (363507 ms total)
> [ PASSED ] 925 tests.
> [ FAILED ] 4 tests, listed below:
> [ FAILED ] FetcherCacheTest.LocalUncached
> [ FAILED ] FetcherCacheTest.RemoveLRUCacheEntries
> [ FAILED ] FetcherCacheHttpTest.HttpCachedSerialized
> [ FAILED ] SlaveRecoveryTest/0.ShutdownSlave, where TypeParam =
> mesos::internal::slave::MesosContainerizer
>
> 4 FAILED TESTS
> YOU HAVE 7 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-1453181562-15918
> Untagged: mesos-1453181562-15918:latest
> Deleted: d5d15187b8af8b5f466f96a209c4af373406a02d0938a48b169cf2976380537f
> Deleted: 298b370834fc713742db11d2be4fe6e34205abb53540824fece15bf8753819b8
> Deleted: 5b2eb20272f35fceae8fdce62e4c57c2478419196e74a3a2bc8c6d98a0618ca0
> Deleted: 06643ff47c057205519445ceae719571a44fcf5954edb1ef95c35fce16cc1265
> Deleted: 01c54e71699d2bc7ca70cb511ef423cc56db6e655c6d2ec71efa338aa6e7b3e8
> Deleted: 507e39554170a3cbf0b5fba5456ecaee6db5e24fd25e8d4995698673146e5efa
> Deleted: 96a2bb91a832dc44b76166788e027d34a9580fbda947551159744a4c9990b52b
> Deleted: 570bf5d82d9c1e1fceedb64f4847b443cdcea88e7eff00d5fc863416c2c08a2f
> Deleted: c7dbbed2cc203b0a90465997fc6c11dce9a668d74eba0fb26db0f1e0ca26fe6e
> Deleted: 741feff04701ff2eaff61991e8487723bd02323e451802617826872a39cb5906
> Deleted: 6f8e12497ca1ae6d36d30dae115ee8c475895f42678b1d50a3aaeaa559db5ba9
> Deleted: 1608b25b81da326dff342838b830b408e94133a9dbf71dad68e9209e4299f963
> Deleted: 0e465a1a7583370979c9fb1421a284d427288f443061e6bde7fea8fad41854b7
> Deleted: 2a6e5a016b8dff4bf0161a7e3ac55391f6fa06a290fadadc7bc2a69ab62b034b
>
> Error handling URL
> https://reviews.apache.org/api/review-requests/41308/reviews/: INTERNAL
> SERVER ERROR
> git clean -fd
> git reset --hard e7b4ba423f380113ab1937a3c506d82b3b8169ea
>
> Build step 'Execute shell' marked build as failure
>
Jenkins build is back to normal : mesos-reviewbot #10917
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10917/changes>
Build failed in Jenkins: mesos-reviewbot #10916
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10916/>
------------------------------------------
[...truncated 167926 lines...]
I0119 07:57:02.885329 31621 recover.cpp:447] Starting replica recovery
I0119 07:57:02.885846 31621 recover.cpp:473] Replica is in EMPTY status
I0119 07:57:02.887238 31611 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13731)@172.17.0.4:56511
I0119 07:57:02.887635 31612 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0119 07:57:02.888188 31612 recover.cpp:564] Updating replica status to STARTING
I0119 07:57:02.889259 31618 master.cpp:374] Master b68b936c-515b-4006-bf19-2f4c0675ed31 (55edfbbe8b31) started on 172.17.0.4:56511
I0119 07:57:02.889282 31618 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/49qfuj/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/49qfuj/master" --zk_session_timeout="10secs"
I0119 07:57:02.889627 31618 master.cpp:423] Master allowing unauthenticated frameworks to register
I0119 07:57:02.889641 31618 master.cpp:426] Master only allowing authenticated slaves to register
I0119 07:57:02.889650 31618 credentials.hpp:35] Loading credentials for authentication from '/tmp/49qfuj/credentials'
I0119 07:57:02.890033 31618 master.cpp:466] Using default 'crammd5' authenticator
I0119 07:57:02.890185 31618 master.cpp:535] Using default 'basic' HTTP authenticator
I0119 07:57:02.890332 31618 master.cpp:569] Authorization enabled
I0119 07:57:02.890513 31609 whitelist_watcher.cpp:77] No whitelist given
I0119 07:57:02.890538 31617 hierarchical.cpp:145] Initialized hierarchical allocator process
I0119 07:57:02.892325 31606 master.cpp:1710] The newly elected leader is master@172.17.0.4:56511 with id b68b936c-515b-4006-bf19-2f4c0675ed31
I0119 07:57:02.892361 31606 master.cpp:1723] Elected as the leading master!
I0119 07:57:02.892379 31606 master.cpp:1468] Recovering from registrar
I0119 07:57:02.892633 31606 registrar.cpp:307] Recovering registrar
I0119 07:57:02.922184 31612 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 33.736821ms
I0119 07:57:02.922266 31612 replica.cpp:320] Persisted replica status to STARTING
I0119 07:57:02.922569 31615 recover.cpp:473] Replica is in STARTING status
I0119 07:57:02.923607 31616 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13733)@172.17.0.4:56511
I0119 07:57:02.923840 31610 recover.cpp:193] Received a recover response from a replica in STARTING status
I0119 07:57:02.924340 31606 recover.cpp:564] Updating replica status to VOTING
I0119 07:57:02.955643 31620 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.14598ms
I0119 07:57:02.955682 31620 replica.cpp:320] Persisted replica status to VOTING
I0119 07:57:02.955826 31618 recover.cpp:578] Successfully joined the Paxos group
I0119 07:57:02.956094 31618 recover.cpp:462] Recover process terminated
I0119 07:57:02.956692 31608 log.cpp:659] Attempting to start the writer
I0119 07:57:02.957849 31613 replica.cpp:493] Replica received implicit promise request from (13734)@172.17.0.4:56511 with proposal 1
I0119 07:57:02.989007 31613 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.118581ms
I0119 07:57:02.989047 31613 replica.cpp:342] Persisted promised to 1
I0119 07:57:02.990038 31615 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0119 07:57:02.991636 31610 replica.cpp:388] Replica received explicit promise request from (13735)@172.17.0.4:56511 for position 0 with proposal 2
I0119 07:57:03.022438 31610 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 30.650424ms
I0119 07:57:03.022478 31610 replica.cpp:712] Persisted action at 0
I0119 07:57:03.023813 31606 replica.cpp:537] Replica received write request for position 0 from (13736)@172.17.0.4:56511
I0119 07:57:03.023876 31606 leveldb.cpp:436] Reading position from leveldb took 29766ns
I0119 07:57:03.055954 31606 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 32.022392ms
I0119 07:57:03.056046 31606 replica.cpp:712] Persisted action at 0
I0119 07:57:03.057267 31617 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0119 07:57:03.089540 31617 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 32.191278ms
I0119 07:57:03.089632 31617 replica.cpp:712] Persisted action at 0
I0119 07:57:03.089664 31617 replica.cpp:697] Replica learned NOP action at position 0
I0119 07:57:03.090490 31616 log.cpp:675] Writer started with ending position 0
I0119 07:57:03.091759 31610 leveldb.cpp:436] Reading position from leveldb took 63929ns
I0119 07:57:03.092821 31613 registrar.cpp:340] Successfully fetched the registry (0B) in 200.1408ms
I0119 07:57:03.092957 31613 registrar.cpp:439] Applied 1 operations in 41474ns; attempting to update the 'registry'
I0119 07:57:03.093735 31619 log.cpp:683] Attempting to append 170 bytes to the log
I0119 07:57:03.093865 31609 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0119 07:57:03.094825 31615 replica.cpp:537] Replica received write request for position 1 from (13737)@172.17.0.4:56511
I0119 07:57:03.124975 31615 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 30.076579ms
I0119 07:57:03.125027 31615 replica.cpp:712] Persisted action at 1
I0119 07:57:03.125682 31610 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0119 07:57:03.150094 31610 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.370391ms
I0119 07:57:03.150169 31610 replica.cpp:712] Persisted action at 1
I0119 07:57:03.150197 31610 replica.cpp:697] Replica learned APPEND action at position 1
I0119 07:57:03.151582 31606 registrar.cpp:484] Successfully updated the 'registry' in 58.508032ms
I0119 07:57:03.151716 31606 registrar.cpp:370] Successfully recovered registrar
I0119 07:57:03.151855 31609 log.cpp:702] Attempting to truncate the log to 1
I0119 07:57:03.152072 31620 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0119 07:57:03.152211 31616 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0119 07:57:03.152282 31607 hierarchical.cpp:172] Skipping recovery of hierarchical allocator: nothing to recover
I0119 07:57:03.153151 31609 replica.cpp:537] Replica received write request for position 2 from (13738)@172.17.0.4:56511
I0119 07:57:03.175072 31609 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 21.859067ms
I0119 07:57:03.175148 31609 replica.cpp:712] Persisted action at 2
I0119 07:57:03.176496 31614 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0119 07:57:03.200191 31614 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 23.654061ms
I0119 07:57:03.200275 31614 leveldb.cpp:399] Deleting ~1 keys from leveldb took 38848ns
I0119 07:57:03.200297 31614 replica.cpp:712] Persisted action at 2
I0119 07:57:03.200322 31614 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0119 07:57:03.203378 31587 scheduler.cpp:154] Version: 0.27.0
I0119 07:57:03.204092 31609 scheduler.cpp:236] New master detected at master@172.17.0.4:56511
I0119 07:57:03.205646 31609 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.4:56511
I0119 07:57:03.207983 31614 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0119 07:57:03.208483 31614 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:47253
I0119 07:57:03.208709 31614 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0119 07:57:03.208770 31614 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0119 07:57:03.209044 31614 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0119 07:57:03.209537 31612 master.hpp:1665] Sending heartbeat to b68b936c-515b-4006-bf19-2f4c0675ed31-0000
I0119 07:57:03.209550 31611 hierarchical.cpp:266] Added framework b68b936c-515b-4006-bf19-2f4c0675ed31-0000
I0119 07:57:03.209616 31611 hierarchical.cpp:1338] No resources available to allocate!
I0119 07:57:03.209645 31611 hierarchical.cpp:1432] No inverse offers to send out!
I0119 07:57:03.209664 31611 hierarchical.cpp:1086] Performed allocation for 0 slaves in 92640ns
I0119 07:57:03.210312 31621 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.4:56511
I0119 07:57:03.210677 31621 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.4:56511
I0119 07:57:03.211140 31616 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0119 07:57:03.211489 31616 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.4:56511
I0119 07:57:03.213531 31617 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0119 07:57:03.213877 31617 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:47254
I0119 07:57:03.214056 31617 master.cpp:2717] Processing REQUEST call for framework b68b936c-515b-4006-bf19-2f4c0675ed31-0000 (default)
I0119 07:57:03.214232 31621 hierarchical.cpp:586] Received resource request from framework b68b936c-515b-4006-bf19-2f4c0675ed31-0000
I0119 07:57:03.214619 31587 master.cpp:1025] Master terminating
I0119 07:57:03.214907 31620 hierarchical.cpp:327] Removed framework b68b936c-515b-4006-bf19-2f4c0675ed31-0000
E0119 07:57:03.217048 31619 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (479 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0119 07:57:03.310220 31587 leveldb.cpp:174] Opened db in 88.102361ms
I0119 07:57:03.343948 31587 leveldb.cpp:181] Compacted db in 33.653306ms
I0119 07:57:03.344086 31587 leveldb.cpp:196] Created db iterator in 23093ns
I0119 07:57:03.344102 31587 leveldb.cpp:202] Seeked to beginning of db in 2824ns
I0119 07:57:03.344111 31587 leveldb.cpp:271] Iterated through 0 keys in the db in 207ns
I0119 07:57:03.344157 31587 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0119 07:57:03.344970 31610 recover.cpp:447] Starting replica recovery
I0119 07:57:03.345274 31619 recover.cpp:473] Replica is in EMPTY status
I0119 07:57:03.346647 31612 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13746)@172.17.0.4:56511
I0119 07:57:03.346887 31613 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0119 07:57:03.347091 31617 master.cpp:374] Master a045e006-d939-48b2-9e97-9ac299cc608a (55edfbbe8b31) started on 172.17.0.4:56511
I0119 07:57:03.347463 31619 recover.cpp:564] Updating replica status to STARTING
I0119 07:57:03.347121 31617 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/HnB5e6/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/HnB5e6/master" --zk_session_timeout="10secs"
I0119 07:57:03.347518 31617 master.cpp:423] Master allowing unauthenticated frameworks to register
I0119 07:57:03.347535 31617 master.cpp:426] Master only allowing authenticated slaves to register
I0119 07:57:03.347548 31617 credentials.hpp:35] Loading credentials for authentication from '/tmp/HnB5e6/credentials'
I0119 07:57:03.347959 31617 master.cpp:466] Using default 'crammd5' authenticator
I0119 07:57:03.348323 31617 master.cpp:535] Using default 'basic' HTTP authenticator
I0119 07:57:03.348466 31617 master.cpp:569] Authorization enabled
I0119 07:57:03.348659 31616 hierarchical.cpp:145] Initialized hierarchical allocator process
I0119 07:57:03.348664 31620 whitelist_watcher.cpp:77] No whitelist given
I0119 07:57:03.350555 31614 master.cpp:1710] The newly elected leader is master@172.17.0.4:56511 with id a045e006-d939-48b2-9e97-9ac299cc608a
I0119 07:57:03.350592 31614 master.cpp:1723] Elected as the leading master!
I0119 07:57:03.350611 31614 master.cpp:1468] Recovering from registrar
I0119 07:57:03.350736 31620 registrar.cpp:307] Recovering registrar
I0119 07:57:03.376865 31615 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 29.256596ms
I0119 07:57:03.376925 31615 replica.cpp:320] Persisted replica status to STARTING
I0119 07:57:03.377209 31614 recover.cpp:473] Replica is in STARTING status
I0119 07:57:03.378895 31615 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13748)@172.17.0.4:56511
I0119 07:57:03.379243 31618 recover.cpp:193] Received a recover response from a replica in STARTING status
I0119 07:57:03.380059 31618 recover.cpp:564] Updating replica status to VOTING
I0119 07:57:03.410358 31618 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.037435ms
I0119 07:57:03.410457 31618 replica.cpp:320] Persisted replica status to VOTING
I0119 07:57:03.410734 31618 recover.cpp:578] Successfully joined the Paxos group
I0119 07:57:03.410946 31618 recover.cpp:462] Recover process terminated
I0119 07:57:03.411628 31616 log.cpp:659] Attempting to start the writer
I0119 07:57:03.413441 31609 replica.cpp:493] Replica received implicit promise request from (13749)@172.17.0.4:56511 with proposal 1
I0119 07:57:03.440351 31609 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 26.85338ms
I0119 07:57:03.440430 31609 replica.cpp:342] Persisted promised to 1
I0119 07:57:03.441615 31606 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0119 07:57:03.443056 31617 replica.cpp:388] Replica received explicit promise request from (13750)@172.17.0.4:56511 for position 0 with proposal 2
I0119 07:57:03.473742 31617 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 30.623264ms
I0119 07:57:03.473811 31617 replica.cpp:712] Persisted action at 0
I0119 07:57:03.475025 31617 replica.cpp:537] Replica received write request for position 0 from (13751)@172.17.0.4:56511
I0119 07:57:03.475103 31617 leveldb.cpp:436] Reading position from leveldb took 38485ns
I0119 07:57:03.507212 31617 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 32.05077ms
I0119 07:57:03.507289 31617 replica.cpp:712] Persisted action at 0
I0119 07:57:03.508100 31606 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0119 07:57:03.540541 31606 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 32.391458ms
I0119 07:57:03.540618 31606 replica.cpp:712] Persisted action at 0
I0119 07:57:03.540652 31606 replica.cpp:697] Replica learned NOP action at position 0
I0119 07:57:03.541726 31618 log.cpp:675] Writer started with ending position 0
I0119 07:57:03.543143 31618 leveldb.cpp:436] Reading position from leveldb took 48738ns
I0119 07:57:03.544337 31618 registrar.cpp:340] Successfully fetched the registry (0B) in 193.5488ms
I0119 07:57:03.544452 31618 registrar.cpp:439] Applied 1 operations in 34367ns; attempting to update the 'registry'
I0119 07:57:03.545615 31618 log.cpp:683] Attempting to append 170 bytes to the log
I0119 07:57:03.545794 31618 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0119 07:57:03.546650 31619 replica.cpp:537] Replica received write request for position 1 from (13752)@172.17.0.4:56511
I0119 07:57:03.574049 31619 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 27.181165ms
I0119 07:57:03.574134 31619 replica.cpp:712] Persisted action at 1
I0119 07:57:03.575367 31608 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0119 07:57:03.607578 31608 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 32.158077ms
I0119 07:57:03.607662 31608 replica.cpp:712] Persisted action at 1
I0119 07:57:03.607692 31608 replica.cpp:697] Replica learned APPEND action at position 1
I0119 07:57:03.608932 31620 registrar.cpp:484] Successfully updated the 'registry' in 64.409856ms
I0119 07:57:03.609129 31620 registrar.cpp:370] Successfully recovered registrar
I0119 07:57:03.609172 31611 log.cpp:702] Attempting to truncate the log to 1
I0119 07:57:03.609310 31607 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0119 07:57:03.609568 31619 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0119 07:57:03.609586 31621 hierarchical.cpp:172] Skipping recovery of hierarchical allocator: nothing to recover
I0119 07:57:03.610221 31611 replica.cpp:537] Replica received write request for position 2 from (13753)@172.17.0.4:56511
I0119 07:57:03.641005 31611 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 30.738605ms
I0119 07:57:03.641050 31611 replica.cpp:712] Persisted action at 2
I0119 07:57:03.641785 31614 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0119 07:57:03.674515 31614 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 32.698455ms
I0119 07:57:03.674605 31614 leveldb.cpp:399] Deleting ~1 keys from leveldb took 45705ns
I0119 07:57:03.674634 31614 replica.cpp:712] Persisted action at 2
I0119 07:57:03.674656 31614 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0119 07:57:03.681026 31587 scheduler.cpp:154] Version: 0.27.0
I0119 07:57:03.681756 31610 scheduler.cpp:236] New master detected at master@172.17.0.4:56511
I0119 07:57:03.683236 31607 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.4:56511
I0119 07:57:03.686419 31618 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0119 07:57:03.687041 31618 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:47255
I0119 07:57:03.687418 31618 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0119 07:57:03.687486 31618 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0119 07:57:03.687952 31618 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0119 07:57:03.688478 31608 hierarchical.cpp:266] Added framework a045e006-d939-48b2-9e97-9ac299cc608a-0000
I0119 07:57:03.688549 31608 hierarchical.cpp:1338] No resources available to allocate!
I0119 07:57:03.688580 31608 hierarchical.cpp:1432] No inverse offers to send out!
I0119 07:57:03.688596 31618 master.hpp:1665] Sending heartbeat to a045e006-d939-48b2-9e97-9ac299cc608a-0000
I0119 07:57:03.688603 31608 hierarchical.cpp:1086] Performed allocation for 0 slaves in 97499ns
I0119 07:57:03.689860 31618 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.4:56511
I0119 07:57:03.690450 31618 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.4:56511
I0119 07:57:03.690887 31612 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0119 07:57:03.691460 31608 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.4:56511
I0119 07:57:03.693367 31608 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0119 07:57:03.693838 31608 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:47256
I0119 07:57:03.694151 31608 master.cpp:2717] Processing REQUEST call for framework a045e006-d939-48b2-9e97-9ac299cc608a-0000 (default)
I0119 07:57:03.694433 31608 hierarchical.cpp:586] Received resource request from framework a045e006-d939-48b2-9e97-9ac299cc608a-0000
I0119 07:57:03.694864 31587 master.cpp:1025] Master terminating
I0119 07:57:03.695122 31615 hierarchical.cpp:327] Removed framework a045e006-d939-48b2-9e97-9ac299cc608a-0000
E0119 07:57:03.696588 31607 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (481 ms)
[----------] 22 tests from ContentType/SchedulerTest (13898 ms total)
[----------] Global test environment tear-down
2016-01-19 07:57:03,991:31587(0x2b702737e700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:60618] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
[==========] 929 tests from 123 test cases ran. (663244 ms total)
[ PASSED ] 923 tests.
[ FAILED ] 6 tests, listed below:
[ FAILED ] FetcherCacheTest.LocalUncached
[ FAILED ] FetcherCacheTest.LocalUncachedExtract
[ FAILED ] FetcherCacheTest.LocalCachedExtract
[ FAILED ] FetcherCacheTest.SimpleEviction
[ FAILED ] FetcherCacheTest.FallbackFromEviction
[ FAILED ] FetcherCacheTest.RemoveLRUCacheEntries
6 FAILED TESTS
YOU HAVE 7 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-1453187687-1748
Untagged: mesos-1453187687-1748:latest
Deleted: 763c79d3b354ece15f2fddbd9f18b895db0d9bc19e382cc2cceeeb83510c75d3
Deleted: e219c82c334c9771185b33a03c1809f5a0b7c23a8df0b77514b8fccc2a7cea23
Deleted: 984dde59e769d2a08ae54bd32b2057a19c82ed436c1d9ad48f136a4992e17325
Deleted: b22b83cbb46980a48a41f63c3872a958d14570bc9c0de51d87482ee01377fcc8
Deleted: 081b4e52c73e7b770af9ff7b0f931b691d599a1b49a122e932e8011ccb1caa97
Deleted: 754a6a081e5c3da5bd133fa481395bd14f296be3cd771c8a10b804cef902a8ff
Deleted: 49e45148857207fb636ee23a02eae764b111633cec32ddb4c40800060eed52b2
Deleted: 3a5241b9b38d6db592641fdcf635ed63e8e637ec4ceacf0163fdd021dc1c9903
Deleted: fadfb98c1fa8a0fe1e5a3e08c8f8a684f86fed235afabeb1c8a11093bfb567d3
Deleted: ab99d7ca363628423662b057d5dad01e3d611ccd2b074e9d60070721bf0829ad
Deleted: 5ef28fc7715651f5fe6470aacfdd3393de4ed2c324328a57f4543f0a0abaede0
Deleted: 640b99d7879e36f71e00de567094a1fa2f949c1238d9d367a8fd083ee5228d79
Deleted: 308ffb38df65d7f4f3e65960971f24ec206ad7aca4f1dd3aef15b6cbd8fc91db
Deleted: 1b34621d0c9fb58cc40e93e08117ba7744a34924dceac7a93d4f2ef332bf1c45
Error handling URL https://reviews.apache.org/api/review-requests/41308/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard e7b4ba423f380113ab1937a3c506d82b3b8169ea
Build step 'Execute shell' marked build as failure