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/16 02:37:16 UTC
Build failed in Jenkins: mesos-reviewbot #10836
See <https://builds.apache.org/job/mesos-reviewbot/10836/changes>
Changes:
[yujie.jay] Accept the 3-field version of HDFS du output.
[tnachen] Commented on test slowness for SlaveTest.CommandExecutorWithOverride.
------------------------------------------
[...truncated 164299 lines...]
I0116 01:37:09.275951 31502 leveldb.cpp:174] Opened db in 3.849344ms
I0116 01:37:09.277274 31502 leveldb.cpp:181] Compacted db in 1.283722ms
I0116 01:37:09.277336 31502 leveldb.cpp:196] Created db iterator in 20170ns
I0116 01:37:09.277356 31502 leveldb.cpp:202] Seeked to beginning of db in 2247ns
I0116 01:37:09.277367 31502 leveldb.cpp:271] Iterated through 0 keys in the db in 225ns
I0116 01:37:09.277410 31502 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0116 01:37:09.278069 31528 recover.cpp:447] Starting replica recovery
I0116 01:37:09.278465 31532 recover.cpp:473] Replica is in EMPTY status
I0116 01:37:09.279541 31532 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13735)@172.17.0.2:42853
I0116 01:37:09.280063 31521 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0116 01:37:09.280642 31536 recover.cpp:564] Updating replica status to STARTING
I0116 01:37:09.281442 31523 master.cpp:374] Master 416d9ed6-28f9-423f-be95-f4330e01ab41 (8215283e883c) started on 172.17.0.2:42853
I0116 01:37:09.281572 31534 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 748835ns
I0116 01:37:09.281702 31534 replica.cpp:320] Persisted replica status to STARTING
I0116 01:37:09.281476 31523 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/h8ftZd/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/h8ftZd/master" --zk_session_timeout="10secs"
I0116 01:37:09.281893 31523 master.cpp:423] Master allowing unauthenticated frameworks to register
I0116 01:37:09.281918 31523 master.cpp:426] Master only allowing authenticated slaves to register
I0116 01:37:09.281935 31523 credentials.hpp:35] Loading credentials for authentication from '/tmp/h8ftZd/credentials'
I0116 01:37:09.282024 31528 recover.cpp:473] Replica is in STARTING status
I0116 01:37:09.282310 31523 master.cpp:466] Using default 'crammd5' authenticator
I0116 01:37:09.282471 31523 master.cpp:535] Using default 'basic' HTTP authenticator
I0116 01:37:09.282641 31523 master.cpp:569] Authorization enabled
I0116 01:37:09.282909 31531 whitelist_watcher.cpp:77] No whitelist given
I0116 01:37:09.283004 31525 hierarchical.cpp:145] Initialized hierarchical allocator process
I0116 01:37:09.283291 31531 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13737)@172.17.0.2:42853
I0116 01:37:09.283793 31536 recover.cpp:193] Received a recover response from a replica in STARTING status
I0116 01:37:09.284338 31532 recover.cpp:564] Updating replica status to VOTING
I0116 01:37:09.285123 31529 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 498878ns
I0116 01:37:09.285166 31529 replica.cpp:320] Persisted replica status to VOTING
I0116 01:37:09.285356 31531 recover.cpp:578] Successfully joined the Paxos group
I0116 01:37:09.285425 31529 master.cpp:1710] The newly elected leader is master@172.17.0.2:42853 with id 416d9ed6-28f9-423f-be95-f4330e01ab41
I0116 01:37:09.285465 31529 master.cpp:1723] Elected as the leading master!
I0116 01:37:09.285485 31529 master.cpp:1468] Recovering from registrar
I0116 01:37:09.285640 31526 registrar.cpp:307] Recovering registrar
I0116 01:37:09.285646 31531 recover.cpp:462] Recover process terminated
I0116 01:37:09.286547 31535 log.cpp:659] Attempting to start the writer
I0116 01:37:09.287936 31528 replica.cpp:493] Replica received implicit promise request from (13738)@172.17.0.2:42853 with proposal 1
I0116 01:37:09.288508 31528 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 534980ns
I0116 01:37:09.288537 31528 replica.cpp:342] Persisted promised to 1
I0116 01:37:09.289288 31536 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0116 01:37:09.290791 31536 replica.cpp:388] Replica received explicit promise request from (13739)@172.17.0.2:42853 for position 0 with proposal 2
I0116 01:37:09.291451 31536 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 584976ns
I0116 01:37:09.291482 31536 replica.cpp:712] Persisted action at 0
I0116 01:37:09.292696 31528 replica.cpp:537] Replica received write request for position 0 from (13740)@172.17.0.2:42853
I0116 01:37:09.292771 31528 leveldb.cpp:436] Reading position from leveldb took 32327ns
I0116 01:37:09.293468 31528 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 621551ns
I0116 01:37:09.293501 31528 replica.cpp:712] Persisted action at 0
I0116 01:37:09.294205 31524 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0116 01:37:09.294899 31524 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 650675ns
I0116 01:37:09.294929 31524 replica.cpp:712] Persisted action at 0
I0116 01:37:09.294953 31524 replica.cpp:697] Replica learned NOP action at position 0
I0116 01:37:09.295635 31523 log.cpp:675] Writer started with ending position 0
I0116 01:37:09.296749 31524 leveldb.cpp:436] Reading position from leveldb took 29740ns
I0116 01:37:09.297852 31536 registrar.cpp:340] Successfully fetched the registry (0B) in 12.118016ms
I0116 01:37:09.297976 31536 registrar.cpp:439] Applied 1 operations in 31327ns; attempting to update the 'registry'
I0116 01:37:09.298777 31521 log.cpp:683] Attempting to append 170 bytes to the log
I0116 01:37:09.298964 31529 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0116 01:37:09.299986 31532 replica.cpp:537] Replica received write request for position 1 from (13741)@172.17.0.2:42853
I0116 01:37:09.300698 31532 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 664734ns
I0116 01:37:09.300729 31532 replica.cpp:712] Persisted action at 1
I0116 01:37:09.301426 31523 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0116 01:37:09.302099 31523 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 636095ns
I0116 01:37:09.302130 31523 replica.cpp:712] Persisted action at 1
I0116 01:37:09.302152 31523 replica.cpp:697] Replica learned APPEND action at position 1
I0116 01:37:09.303323 31523 registrar.cpp:484] Successfully updated the 'registry' in 5.276928ms
I0116 01:37:09.303506 31523 registrar.cpp:370] Successfully recovered registrar
I0116 01:37:09.303594 31532 log.cpp:702] Attempting to truncate the log to 1
I0116 01:37:09.303997 31534 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0116 01:37:09.304245 31533 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0116 01:37:09.304260 31523 hierarchical.cpp:163] Skipping recovery of hierarchical allocator: nothing to recover
I0116 01:37:09.304992 31536 replica.cpp:537] Replica received write request for position 2 from (13742)@172.17.0.2:42853
I0116 01:37:09.305749 31536 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 707630ns
I0116 01:37:09.305780 31536 replica.cpp:712] Persisted action at 2
I0116 01:37:09.306537 31530 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0116 01:37:09.307142 31530 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 561954ns
I0116 01:37:09.307212 31530 leveldb.cpp:399] Deleting ~1 keys from leveldb took 39814ns
I0116 01:37:09.307238 31530 replica.cpp:712] Persisted action at 2
I0116 01:37:09.307261 31530 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0116 01:37:09.315031 31502 scheduler.cpp:154] Version: 0.27.0
I0116 01:37:09.315690 31534 scheduler.cpp:236] New master detected at master@172.17.0.2:42853
I0116 01:37:09.316869 31532 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:42853
I0116 01:37:09.318976 31524 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0116 01:37:09.319485 31524 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:42220
I0116 01:37:09.319700 31524 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0116 01:37:09.319766 31524 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0116 01:37:09.320125 31527 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0116 01:37:09.320541 31523 hierarchical.cpp:257] Added framework 416d9ed6-28f9-423f-be95-f4330e01ab41-0000
I0116 01:37:09.320615 31523 hierarchical.cpp:1327] No resources available to allocate!
I0116 01:37:09.320663 31523 hierarchical.cpp:1421] No inverse offers to send out!
I0116 01:37:09.320684 31524 master.hpp:1658] Sending heartbeat to 416d9ed6-28f9-423f-be95-f4330e01ab41-0000
I0116 01:37:09.320695 31523 hierarchical.cpp:1077] Performed allocation for 0 slaves in 124042ns
I0116 01:37:09.321741 31524 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:42853
I0116 01:37:09.322250 31524 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:42853
I0116 01:37:09.323020 31531 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0116 01:37:09.323271 31534 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:42853
I0116 01:37:09.324782 31534 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0116 01:37:09.325250 31533 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:42221
I0116 01:37:09.325361 31533 master.cpp:2717] Processing REQUEST call for framework 416d9ed6-28f9-423f-be95-f4330e01ab41-0000 (default)
I0116 01:37:09.325508 31529 hierarchical.cpp:577] Received resource request from framework 416d9ed6-28f9-423f-be95-f4330e01ab41-0000
I0116 01:37:09.325978 31526 master.cpp:1025] Master terminating
I0116 01:37:09.326391 31528 hierarchical.cpp:318] Removed framework 416d9ed6-28f9-423f-be95-f4330e01ab41-0000
E0116 01:37:09.327512 31525 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (62 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0116 01:37:09.336493 31502 leveldb.cpp:174] Opened db in 3.303843ms
I0116 01:37:09.337700 31502 leveldb.cpp:181] Compacted db in 1.166802ms
I0116 01:37:09.337767 31502 leveldb.cpp:196] Created db iterator in 20157ns
I0116 01:37:09.337788 31502 leveldb.cpp:202] Seeked to beginning of db in 2117ns
I0116 01:37:09.337800 31502 leveldb.cpp:271] Iterated through 0 keys in the db in 310ns
I0116 01:37:09.337867 31502 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0116 01:37:09.338282 31532 recover.cpp:447] Starting replica recovery
I0116 01:37:09.338731 31532 recover.cpp:473] Replica is in EMPTY status
I0116 01:37:09.339922 31528 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13750)@172.17.0.2:42853
I0116 01:37:09.340360 31524 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0116 01:37:09.340996 31531 recover.cpp:564] Updating replica status to STARTING
I0116 01:37:09.341720 31529 master.cpp:374] Master 2f71c640-bb52-42b3-9457-24cfdc352c81 (8215283e883c) started on 172.17.0.2:42853
I0116 01:37:09.341811 31536 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 607716ns
I0116 01:37:09.341892 31536 replica.cpp:320] Persisted replica status to STARTING
I0116 01:37:09.341804 31529 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/JpGALz/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/JpGALz/master" --zk_session_timeout="10secs"
I0116 01:37:09.342125 31531 recover.cpp:473] Replica is in STARTING status
I0116 01:37:09.342172 31529 master.cpp:423] Master allowing unauthenticated frameworks to register
I0116 01:37:09.342185 31529 master.cpp:426] Master only allowing authenticated slaves to register
I0116 01:37:09.342192 31529 credentials.hpp:35] Loading credentials for authentication from '/tmp/JpGALz/credentials'
I0116 01:37:09.342629 31529 master.cpp:466] Using default 'crammd5' authenticator
I0116 01:37:09.342779 31529 master.cpp:535] Using default 'basic' HTTP authenticator
I0116 01:37:09.343128 31529 master.cpp:569] Authorization enabled
I0116 01:37:09.343348 31525 hierarchical.cpp:145] Initialized hierarchical allocator process
I0116 01:37:09.343381 31530 whitelist_watcher.cpp:77] No whitelist given
I0116 01:37:09.343397 31531 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13752)@172.17.0.2:42853
I0116 01:37:09.343715 31535 recover.cpp:193] Received a recover response from a replica in STARTING status
I0116 01:37:09.344588 31524 recover.cpp:564] Updating replica status to VOTING
I0116 01:37:09.345343 31527 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 528150ns
I0116 01:37:09.345374 31527 replica.cpp:320] Persisted replica status to VOTING
I0116 01:37:09.345652 31523 recover.cpp:578] Successfully joined the Paxos group
I0116 01:37:09.345806 31526 master.cpp:1710] The newly elected leader is master@172.17.0.2:42853 with id 2f71c640-bb52-42b3-9457-24cfdc352c81
I0116 01:37:09.345865 31526 master.cpp:1723] Elected as the leading master!
I0116 01:37:09.345896 31526 master.cpp:1468] Recovering from registrar
I0116 01:37:09.346050 31527 registrar.cpp:307] Recovering registrar
I0116 01:37:09.346083 31523 recover.cpp:462] Recover process terminated
I0116 01:37:09.346989 31529 log.cpp:659] Attempting to start the writer
I0116 01:37:09.348317 31522 replica.cpp:493] Replica received implicit promise request from (13753)@172.17.0.2:42853 with proposal 1
I0116 01:37:09.348836 31522 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 457057ns
I0116 01:37:09.348866 31522 replica.cpp:342] Persisted promised to 1
I0116 01:37:09.349611 31525 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0116 01:37:09.351063 31535 replica.cpp:388] Replica received explicit promise request from (13754)@172.17.0.2:42853 for position 0 with proposal 2
I0116 01:37:09.351743 31535 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 627720ns
I0116 01:37:09.351774 31535 replica.cpp:712] Persisted action at 0
I0116 01:37:09.353008 31532 replica.cpp:537] Replica received write request for position 0 from (13755)@172.17.0.2:42853
I0116 01:37:09.353078 31532 leveldb.cpp:436] Reading position from leveldb took 32374ns
I0116 01:37:09.353827 31532 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 683162ns
I0116 01:37:09.353860 31532 replica.cpp:712] Persisted action at 0
I0116 01:37:09.354534 31522 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0116 01:37:09.355242 31522 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 667114ns
I0116 01:37:09.355273 31522 replica.cpp:712] Persisted action at 0
I0116 01:37:09.355294 31522 replica.cpp:697] Replica learned NOP action at position 0
I0116 01:37:09.356047 31530 log.cpp:675] Writer started with ending position 0
I0116 01:37:09.357168 31524 leveldb.cpp:436] Reading position from leveldb took 30062ns
I0116 01:37:09.358134 31522 registrar.cpp:340] Successfully fetched the registry (0B) in 12.029696ms
I0116 01:37:09.358275 31522 registrar.cpp:439] Applied 1 operations in 34467ns; attempting to update the 'registry'
I0116 01:37:09.359138 31527 log.cpp:683] Attempting to append 170 bytes to the log
I0116 01:37:09.359277 31535 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0116 01:37:09.360127 31523 replica.cpp:537] Replica received write request for position 1 from (13756)@172.17.0.2:42853
I0116 01:37:09.360849 31523 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 676624ns
I0116 01:37:09.360882 31523 replica.cpp:712] Persisted action at 1
I0116 01:37:09.361479 31523 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0116 01:37:09.362192 31523 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 675947ns
I0116 01:37:09.362224 31523 replica.cpp:712] Persisted action at 1
I0116 01:37:09.362246 31523 replica.cpp:697] Replica learned APPEND action at position 1
I0116 01:37:09.363299 31536 registrar.cpp:484] Successfully updated the 'registry' in 4.948992ms
I0116 01:37:09.363464 31536 registrar.cpp:370] Successfully recovered registrar
I0116 01:37:09.363546 31531 log.cpp:702] Attempting to truncate the log to 1
I0116 01:37:09.363675 31526 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0116 01:37:09.364079 31529 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0116 01:37:09.364114 31521 hierarchical.cpp:163] Skipping recovery of hierarchical allocator: nothing to recover
I0116 01:37:09.364804 31535 replica.cpp:537] Replica received write request for position 2 from (13757)@172.17.0.2:42853
I0116 01:37:09.365519 31535 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 645170ns
I0116 01:37:09.365550 31535 replica.cpp:712] Persisted action at 2
I0116 01:37:09.366230 31522 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0116 01:37:09.366884 31522 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 612666ns
I0116 01:37:09.366956 31522 leveldb.cpp:399] Deleting ~1 keys from leveldb took 40129ns
I0116 01:37:09.366981 31522 replica.cpp:712] Persisted action at 2
I0116 01:37:09.367004 31522 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0116 01:37:09.374899 31502 scheduler.cpp:154] Version: 0.27.0
I0116 01:37:09.375612 31529 scheduler.cpp:236] New master detected at master@172.17.0.2:42853
I0116 01:37:09.376934 31526 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:42853
I0116 01:37:09.379078 31534 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0116 01:37:09.379596 31526 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:42222
I0116 01:37:09.380022 31526 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0116 01:37:09.380086 31526 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0116 01:37:09.380409 31526 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0116 01:37:09.380848 31534 hierarchical.cpp:257] Added framework 2f71c640-bb52-42b3-9457-24cfdc352c81-0000
I0116 01:37:09.380916 31534 hierarchical.cpp:1327] No resources available to allocate!
I0116 01:37:09.380965 31534 hierarchical.cpp:1421] No inverse offers to send out!
I0116 01:37:09.380978 31521 master.hpp:1658] Sending heartbeat to 2f71c640-bb52-42b3-9457-24cfdc352c81-0000
I0116 01:37:09.381001 31534 hierarchical.cpp:1077] Performed allocation for 0 slaves in 122589ns
I0116 01:37:09.381935 31525 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:42853
I0116 01:37:09.382537 31525 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:42853
I0116 01:37:09.383361 31522 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0116 01:37:09.383401 31525 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:42853
I0116 01:37:09.385154 31523 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0116 01:37:09.385648 31528 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:42223
I0116 01:37:09.385921 31528 master.cpp:2717] Processing REQUEST call for framework 2f71c640-bb52-42b3-9457-24cfdc352c81-0000 (default)
I0116 01:37:09.386086 31524 hierarchical.cpp:577] Received resource request from framework 2f71c640-bb52-42b3-9457-24cfdc352c81-0000
I0116 01:37:09.386489 31529 master.cpp:1025] Master terminating
I0116 01:37:09.386885 31524 hierarchical.cpp:318] Removed framework 2f71c640-bb52-42b3-9457-24cfdc352c81-0000
E0116 01:37:09.388006 31527 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (61 ms)
[----------] 22 tests from ContentType/SchedulerTest (4217 ms total)
[----------] Global test environment tear-down
[==========] 928 tests from 123 test cases ran. (343426 ms total)
[ PASSED ] 927 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ReservationTest.ReservationInfoNoPrincipal
1 FAILED TEST
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-1452906550-8708
Untagged: mesos-1452906550-8708:latest
Deleted: d08e0fe75449ea9703ec2b7ba9d84fdaee170346506da1a379249e5212d71403
Deleted: 15457aad0b8696531f5988b7b35796c85bbb3fdba7ffc0a84a4be21991cc5b9c
Deleted: 4177150c8d16e22890dcdda4b4494d3557f5678310303c0b6b2ea6a2b6adc890
Deleted: a0f1706bd65abc220b5fbce3a085b5b401a4dbd5c340a9fa95af5d6f0afe0fce
Deleted: ee559b7cbdb5cebe9153c64c0677ba099b3218832ee2aca7f83a8a44b7fc27e2
Deleted: 2bb33c7cb0482a64b66e4dbcfd827edc383c1a0beb92dab715f0cbeab40424a6
Deleted: b8074e117afaa9c2a333fa5677da885bc46372ffd046d011a1a0998c71087ae6
Deleted: 6265f36511579adc9ffbe8456c9e0755681226deb19086f3afab830829d783c6
Deleted: 4bd2e7aa1c9df8c5ef6d0a5205d364ab1dd3cee04c8b83e7d6a54054b999e56e
Deleted: f09cbc1ad4dcbcb4531675510d6043b7640441f424b312c8fe6f08a8b6b6f629
Deleted: db065d4e5e038be47a7ffe4a767e6fe3ab66690ef6cfd132040717ffc53ac464
Deleted: 24ad6ee04d18bcbab07c346eea29d8851e262937a736221f9330e5b627f272f5
Deleted: 871788a8aad7e6f9d4e06e4ec526d3fe2f14febb0f5a93018373a9c7de2c3f4a
Deleted: 63abd9146f0b96ef1462fcac2fde1d66c25409da3e06aa61f3679af2c9aa2817
Error handling URL https://reviews.apache.org/api/review-requests/42361/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard bcad85d3d8e4471e0ba20725358eb9f6a5c3281f
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : mesos-reviewbot #10839
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10839/>
Build failed in Jenkins: mesos-reviewbot #10838
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10838/>
------------------------------------------
[...truncated 167328 lines...]
I0116 03:48:02.056391 31495 leveldb.cpp:181] Compacted db in 25.452447ms
I0116 03:48:02.056471 31495 leveldb.cpp:196] Created db iterator in 24489ns
I0116 03:48:02.056490 31495 leveldb.cpp:202] Seeked to beginning of db in 2605ns
I0116 03:48:02.056501 31495 leveldb.cpp:271] Iterated through 0 keys in the db in 215ns
I0116 03:48:02.056551 31495 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0116 03:48:02.057377 31519 recover.cpp:447] Starting replica recovery
I0116 03:48:02.057775 31519 recover.cpp:473] Replica is in EMPTY status
I0116 03:48:02.059535 31519 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13747)@172.17.0.5:40893
I0116 03:48:02.059970 31519 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0116 03:48:02.060518 31519 recover.cpp:564] Updating replica status to STARTING
I0116 03:48:02.062049 31523 master.cpp:374] Master f9f86b7d-25e7-43e3-a5df-0d23dbca3463 (71da7b551827) started on 172.17.0.5:40893
I0116 03:48:02.062127 31523 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/ncNfj0/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/ncNfj0/master" --zk_session_timeout="10secs"
I0116 03:48:02.062552 31523 master.cpp:423] Master allowing unauthenticated frameworks to register
I0116 03:48:02.062616 31523 master.cpp:426] Master only allowing authenticated slaves to register
I0116 03:48:02.062696 31523 credentials.hpp:35] Loading credentials for authentication from '/tmp/ncNfj0/credentials'
I0116 03:48:02.063107 31523 master.cpp:466] Using default 'crammd5' authenticator
I0116 03:48:02.063310 31523 master.cpp:535] Using default 'basic' HTTP authenticator
I0116 03:48:02.063498 31523 master.cpp:569] Authorization enabled
I0116 03:48:02.063786 31529 hierarchical.cpp:145] Initialized hierarchical allocator process
I0116 03:48:02.065019 31520 whitelist_watcher.cpp:77] No whitelist given
I0116 03:48:02.066148 31522 master.cpp:1710] The newly elected leader is master@172.17.0.5:40893 with id f9f86b7d-25e7-43e3-a5df-0d23dbca3463
I0116 03:48:02.066179 31522 master.cpp:1723] Elected as the leading master!
I0116 03:48:02.066195 31522 master.cpp:1468] Recovering from registrar
I0116 03:48:02.066437 31522 registrar.cpp:307] Recovering registrar
I0116 03:48:02.081435 31521 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 20.766598ms
I0116 03:48:02.081478 31521 replica.cpp:320] Persisted replica status to STARTING
I0116 03:48:02.081702 31522 recover.cpp:473] Replica is in STARTING status
I0116 03:48:02.082804 31526 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13749)@172.17.0.5:40893
I0116 03:48:02.083178 31522 recover.cpp:193] Received a recover response from a replica in STARTING status
I0116 03:48:02.083724 31529 recover.cpp:564] Updating replica status to VOTING
I0116 03:48:02.106600 31522 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.734606ms
I0116 03:48:02.106642 31522 replica.cpp:320] Persisted replica status to VOTING
I0116 03:48:02.106775 31529 recover.cpp:578] Successfully joined the Paxos group
I0116 03:48:02.107002 31529 recover.cpp:462] Recover process terminated
I0116 03:48:02.107475 31514 log.cpp:659] Attempting to start the writer
I0116 03:48:02.108733 31529 replica.cpp:493] Replica received implicit promise request from (13750)@172.17.0.5:40893 with proposal 1
I0116 03:48:02.131692 31529 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.907466ms
I0116 03:48:02.131770 31529 replica.cpp:342] Persisted promised to 1
I0116 03:48:02.132560 31529 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0116 03:48:02.133939 31527 replica.cpp:388] Replica received explicit promise request from (13751)@172.17.0.5:40893 for position 0 with proposal 2
I0116 03:48:02.156930 31527 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.930583ms
I0116 03:48:02.156991 31527 replica.cpp:712] Persisted action at 0
I0116 03:48:02.158576 31519 replica.cpp:537] Replica received write request for position 0 from (13752)@172.17.0.5:40893
I0116 03:48:02.158632 31519 leveldb.cpp:436] Reading position from leveldb took 26736ns
I0116 03:48:02.182008 31519 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.33538ms
I0116 03:48:02.182054 31519 replica.cpp:712] Persisted action at 0
I0116 03:48:02.182783 31514 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0116 03:48:02.207119 31514 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.302372ms
I0116 03:48:02.207167 31514 replica.cpp:712] Persisted action at 0
I0116 03:48:02.207192 31514 replica.cpp:697] Replica learned NOP action at position 0
I0116 03:48:02.208006 31519 log.cpp:675] Writer started with ending position 0
I0116 03:48:02.209043 31517 leveldb.cpp:436] Reading position from leveldb took 24400ns
I0116 03:48:02.209913 31520 registrar.cpp:340] Successfully fetched the registry (0B) in 143.432704ms
I0116 03:48:02.210047 31520 registrar.cpp:439] Applied 1 operations in 35970ns; attempting to update the 'registry'
I0116 03:48:02.210862 31522 log.cpp:683] Attempting to append 170 bytes to the log
I0116 03:48:02.211025 31514 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0116 03:48:02.211871 31521 replica.cpp:537] Replica received write request for position 1 from (13753)@172.17.0.5:40893
I0116 03:48:02.237627 31521 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 25.693264ms
I0116 03:48:02.237699 31521 replica.cpp:712] Persisted action at 1
I0116 03:48:02.238641 31521 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0116 03:48:02.271173 31521 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 32.488725ms
I0116 03:48:02.271250 31521 replica.cpp:712] Persisted action at 1
I0116 03:48:02.271277 31521 replica.cpp:697] Replica learned APPEND action at position 1
I0116 03:48:02.272930 31520 registrar.cpp:484] Successfully updated the 'registry' in 62.799872ms
I0116 03:48:02.273113 31520 registrar.cpp:370] Successfully recovered registrar
I0116 03:48:02.273262 31523 log.cpp:702] Attempting to truncate the log to 1
I0116 03:48:02.273656 31521 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0116 03:48:02.273977 31528 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0116 03:48:02.274008 31514 hierarchical.cpp:163] Skipping recovery of hierarchical allocator: nothing to recover
I0116 03:48:02.274595 31526 replica.cpp:537] Replica received write request for position 2 from (13754)@172.17.0.5:40893
I0116 03:48:02.304666 31526 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 30.015537ms
I0116 03:48:02.304745 31526 replica.cpp:712] Persisted action at 2
I0116 03:48:02.305816 31519 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0116 03:48:02.338191 31519 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 32.334334ms
I0116 03:48:02.338280 31519 leveldb.cpp:399] Deleting ~1 keys from leveldb took 44441ns
I0116 03:48:02.338304 31519 replica.cpp:712] Persisted action at 2
I0116 03:48:02.338330 31519 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0116 03:48:02.346364 31495 scheduler.cpp:154] Version: 0.27.0
I0116 03:48:02.347067 31522 scheduler.cpp:236] New master detected at master@172.17.0.5:40893
I0116 03:48:02.348086 31526 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:40893
I0116 03:48:02.349959 31516 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0116 03:48:02.350574 31523 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:56918
I0116 03:48:02.350819 31523 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0116 03:48:02.350900 31523 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0116 03:48:02.351235 31523 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0116 03:48:02.351742 31517 hierarchical.cpp:257] Added framework f9f86b7d-25e7-43e3-a5df-0d23dbca3463-0000
I0116 03:48:02.351832 31517 hierarchical.cpp:1327] No resources available to allocate!
I0116 03:48:02.351840 31522 master.hpp:1658] Sending heartbeat to f9f86b7d-25e7-43e3-a5df-0d23dbca3463-0000
I0116 03:48:02.351886 31517 hierarchical.cpp:1421] No inverse offers to send out!
I0116 03:48:02.351927 31517 hierarchical.cpp:1077] Performed allocation for 0 slaves in 149489ns
I0116 03:48:02.352934 31529 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:40893
I0116 03:48:02.353495 31529 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:40893
I0116 03:48:02.354392 31524 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0116 03:48:02.354446 31529 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:40893
I0116 03:48:02.356318 31527 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0116 03:48:02.356842 31520 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:56919
I0116 03:48:02.356982 31520 master.cpp:2717] Processing REQUEST call for framework f9f86b7d-25e7-43e3-a5df-0d23dbca3463-0000 (default)
I0116 03:48:02.357200 31517 hierarchical.cpp:577] Received resource request from framework f9f86b7d-25e7-43e3-a5df-0d23dbca3463-0000
I0116 03:48:02.357684 31523 master.cpp:1025] Master terminating
I0116 03:48:02.358008 31526 hierarchical.cpp:318] Removed framework f9f86b7d-25e7-43e3-a5df-0d23dbca3463-0000
E0116 03:48:02.359376 31529 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (431 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0116 03:48:02.473763 31495 leveldb.cpp:174] Opened db in 107.073197ms
I0116 03:48:02.499572 31495 leveldb.cpp:181] Compacted db in 25.740235ms
I0116 03:48:02.499647 31495 leveldb.cpp:196] Created db iterator in 25949ns
I0116 03:48:02.499667 31495 leveldb.cpp:202] Seeked to beginning of db in 2048ns
I0116 03:48:02.499681 31495 leveldb.cpp:271] Iterated through 0 keys in the db in 285ns
I0116 03:48:02.499743 31495 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0116 03:48:02.500298 31526 recover.cpp:447] Starting replica recovery
I0116 03:48:02.500535 31526 recover.cpp:473] Replica is in EMPTY status
I0116 03:48:02.501704 31519 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13762)@172.17.0.5:40893
I0116 03:48:02.502100 31522 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0116 03:48:02.502516 31517 recover.cpp:564] Updating replica status to STARTING
I0116 03:48:02.503135 31520 master.cpp:374] Master 5ae3164d-7314-4fbc-be04-cd96ea57671b (71da7b551827) started on 172.17.0.5:40893
I0116 03:48:02.503159 31520 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/cAbNhV/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/cAbNhV/master" --zk_session_timeout="10secs"
I0116 03:48:02.503404 31520 master.cpp:423] Master allowing unauthenticated frameworks to register
I0116 03:48:02.503414 31520 master.cpp:426] Master only allowing authenticated slaves to register
I0116 03:48:02.503420 31520 credentials.hpp:35] Loading credentials for authentication from '/tmp/cAbNhV/credentials'
I0116 03:48:02.503700 31520 master.cpp:466] Using default 'crammd5' authenticator
I0116 03:48:02.503830 31520 master.cpp:535] Using default 'basic' HTTP authenticator
I0116 03:48:02.504012 31520 master.cpp:569] Authorization enabled
I0116 03:48:02.504298 31525 hierarchical.cpp:145] Initialized hierarchical allocator process
I0116 03:48:02.504369 31523 whitelist_watcher.cpp:77] No whitelist given
I0116 03:48:02.506381 31526 master.cpp:1710] The newly elected leader is master@172.17.0.5:40893 with id 5ae3164d-7314-4fbc-be04-cd96ea57671b
I0116 03:48:02.506412 31526 master.cpp:1723] Elected as the leading master!
I0116 03:48:02.506433 31526 master.cpp:1468] Recovering from registrar
I0116 03:48:02.506820 31528 registrar.cpp:307] Recovering registrar
I0116 03:48:02.524932 31516 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.28317ms
I0116 03:48:02.524981 31516 replica.cpp:320] Persisted replica status to STARTING
I0116 03:48:02.525243 31515 recover.cpp:473] Replica is in STARTING status
I0116 03:48:02.526118 31526 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13764)@172.17.0.5:40893
I0116 03:48:02.526420 31516 recover.cpp:193] Received a recover response from a replica in STARTING status
I0116 03:48:02.526790 31521 recover.cpp:564] Updating replica status to VOTING
I0116 03:48:02.550153 31528 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 23.238075ms
I0116 03:48:02.550199 31528 replica.cpp:320] Persisted replica status to VOTING
I0116 03:48:02.550350 31522 recover.cpp:578] Successfully joined the Paxos group
I0116 03:48:02.550583 31522 recover.cpp:462] Recover process terminated
I0116 03:48:02.551143 31525 log.cpp:659] Attempting to start the writer
I0116 03:48:02.552580 31518 replica.cpp:493] Replica received implicit promise request from (13765)@172.17.0.5:40893 with proposal 1
I0116 03:48:02.575116 31518 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.495287ms
I0116 03:48:02.575152 31518 replica.cpp:342] Persisted promised to 1
I0116 03:48:02.575742 31520 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0116 03:48:02.576802 31528 replica.cpp:388] Replica received explicit promise request from (13766)@172.17.0.5:40893 for position 0 with proposal 2
I0116 03:48:02.600286 31528 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 23.444039ms
I0116 03:48:02.600342 31528 replica.cpp:712] Persisted action at 0
I0116 03:48:02.601624 31516 replica.cpp:537] Replica received write request for position 0 from (13767)@172.17.0.5:40893
I0116 03:48:02.601730 31516 leveldb.cpp:436] Reading position from leveldb took 32387ns
I0116 03:48:02.625396 31516 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.599926ms
I0116 03:48:02.625481 31516 replica.cpp:712] Persisted action at 0
I0116 03:48:02.626415 31527 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0116 03:48:02.642160 31527 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 15.694206ms
I0116 03:48:02.642231 31527 replica.cpp:712] Persisted action at 0
I0116 03:48:02.642266 31527 replica.cpp:697] Replica learned NOP action at position 0
I0116 03:48:02.643436 31528 log.cpp:675] Writer started with ending position 0
I0116 03:48:02.644976 31528 leveldb.cpp:436] Reading position from leveldb took 56361ns
I0116 03:48:02.646323 31514 registrar.cpp:340] Successfully fetched the registry (0B) in 139.403264ms
I0116 03:48:02.646546 31514 registrar.cpp:439] Applied 1 operations in 41127ns; attempting to update the 'registry'
I0116 03:48:02.647483 31515 log.cpp:683] Attempting to append 170 bytes to the log
I0116 03:48:02.647660 31529 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0116 03:48:02.648950 31521 replica.cpp:537] Replica received write request for position 1 from (13768)@172.17.0.5:40893
I0116 03:48:02.667474 31521 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 18.442697ms
I0116 03:48:02.667574 31521 replica.cpp:712] Persisted action at 1
I0116 03:48:02.668551 31529 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0116 03:48:02.771535 31529 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 102.934536ms
I0116 03:48:02.771618 31529 replica.cpp:712] Persisted action at 1
I0116 03:48:02.771653 31529 replica.cpp:697] Replica learned APPEND action at position 1
I0116 03:48:02.774596 31529 registrar.cpp:484] Successfully updated the 'registry' in 127.958016ms
I0116 03:48:02.775077 31529 registrar.cpp:370] Successfully recovered registrar
I0116 03:48:02.775141 31516 log.cpp:702] Attempting to truncate the log to 1
I0116 03:48:02.775463 31516 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0116 03:48:02.775780 31529 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0116 03:48:02.776407 31516 hierarchical.cpp:163] Skipping recovery of hierarchical allocator: nothing to recover
I0116 03:48:02.777123 31516 replica.cpp:537] Replica received write request for position 2 from (13769)@172.17.0.5:40893
I0116 03:48:02.807467 31516 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 30.27245ms
I0116 03:48:02.807566 31516 replica.cpp:712] Persisted action at 2
I0116 03:48:02.808509 31517 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0116 03:48:02.837065 31517 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 28.49989ms
I0116 03:48:02.837234 31517 leveldb.cpp:399] Deleting ~1 keys from leveldb took 79996ns
I0116 03:48:02.837257 31517 replica.cpp:712] Persisted action at 2
I0116 03:48:02.837292 31517 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0116 03:48:02.847779 31495 scheduler.cpp:154] Version: 0.27.0
I0116 03:48:02.849122 31525 scheduler.cpp:236] New master detected at master@172.17.0.5:40893
I0116 03:48:02.850654 31527 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:40893
I0116 03:48:02.853168 31521 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0116 03:48:02.853670 31529 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:56920
I0116 03:48:02.854070 31529 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0116 03:48:02.854135 31529 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0116 03:48:02.854471 31522 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0116 03:48:02.854934 31521 hierarchical.cpp:257] Added framework 5ae3164d-7314-4fbc-be04-cd96ea57671b-0000
I0116 03:48:02.854933 31526 master.hpp:1658] Sending heartbeat to 5ae3164d-7314-4fbc-be04-cd96ea57671b-0000
I0116 03:48:02.855026 31521 hierarchical.cpp:1327] No resources available to allocate!
I0116 03:48:02.855059 31521 hierarchical.cpp:1421] No inverse offers to send out!
I0116 03:48:02.855082 31521 hierarchical.cpp:1077] Performed allocation for 0 slaves in 108828ns
I0116 03:48:02.855808 31526 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:40893
I0116 03:48:02.856343 31526 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:40893
I0116 03:48:02.857084 31525 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0116 03:48:02.857115 31522 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:40893
I0116 03:48:02.859011 31525 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0116 03:48:02.859547 31515 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:56921
I0116 03:48:02.859839 31515 master.cpp:2717] Processing REQUEST call for framework 5ae3164d-7314-4fbc-be04-cd96ea57671b-0000 (default)
I0116 03:48:02.860043 31521 hierarchical.cpp:577] Received resource request from framework 5ae3164d-7314-4fbc-be04-cd96ea57671b-0000
I0116 03:48:02.860512 31515 master.cpp:1025] Master terminating
I0116 03:48:02.860913 31527 hierarchical.cpp:318] Removed framework 5ae3164d-7314-4fbc-be04-cd96ea57671b-0000
E0116 03:48:02.862390 31516 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (504 ms)
[----------] 22 tests from ContentType/SchedulerTest (13078 ms total)
[----------] Global test environment tear-down
2016-01-16 03:48:03,440:31495(0x2b69e6303700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:44698] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
[==========] 928 tests from 123 test cases ran. (665002 ms total)
[ PASSED ] 927 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ReservationTest.ReservationInfoNoPrincipal
1 FAILED TEST
YOU HAVE 7 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[3]: *** [check-am] Error 2
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1452913583-17729
Untagged: mesos-1452913583-17729:latest
Deleted: 6dfaaa4c0fa32175792d4761b6f8ad2b8478c4359ffecf2259211805589d0713
Deleted: 961f1cec319030cc3ded2b36697dd9c6c75ee9fe9822591f4b7f069085ef5570
Deleted: 9e11a39add5df0e1ad7ccb53cc9493caa91eeb2bcbea3d74e4e544c9433e07c6
Deleted: 2cf91c30093bfb98bf518d5b0e0b51f38eb9e95bf87d9827263ec3faac202a4d
Deleted: ae5e28a5ecc710d64fe404b1f9865649c522ae9ef55f18c8d7e02e26b8c1c5e1
Deleted: 600e38107ecffed9876c50dbb8f5e22390da20933a1e43d2b8ee45e61f9d5027
Deleted: 323d05f9f318505853c06fd1ae0b3c14bdc97332a0f103da2b8be6d2e8af1258
Deleted: 86c947e513af4031cf8bf1c572b0801e780213d6b7af111a0a9ea1fece657a9f
Deleted: 755a26a6977ef89728ee88c665174de353afcacb1e625c33328bb96fbaeadb2c
Deleted: 1002221f067584cd4a4ce908508ec80d4e721d15c7c319f438bf2985c0315552
Deleted: 9c9a731633698efb38ed1903fbeeaf23278ab1ebd4e507480e3027d3a888f676
Deleted: 1aa8cfe184b685cabbf059bd4e2032340a6afe679465c9ef9ce1cbb3d387b298
Deleted: 7c5970904f91fa9be84134667c29f257f8d1aa7a07fc7c6cd09cb3c86f2275e9
Deleted: 2529798f28db5f17b3efc26b6c09296f990f062e7e960cf096235c4d533540e5
Error handling URL https://reviews.apache.org/api/review-requests/42361/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard c8c4901b2d7fad7347c67a0cc155cf281c4f2c24
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: mesos-reviewbot #10837
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10837/changes>
Changes:
[vinodkone] Added Tachyon to the list of frameworks.
------------------------------------------
[...truncated 167945 lines...]
I0116 02:37:51.193373 31504 leveldb.cpp:174] Opened db in 120.375035ms
I0116 02:37:51.243927 31504 leveldb.cpp:181] Compacted db in 50.506524ms
I0116 02:37:51.244009 31504 leveldb.cpp:196] Created db iterator in 22263ns
I0116 02:37:51.244024 31504 leveldb.cpp:202] Seeked to beginning of db in 1891ns
I0116 02:37:51.244031 31504 leveldb.cpp:271] Iterated through 0 keys in the db in 169ns
I0116 02:37:51.244073 31504 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0116 02:37:51.244834 31524 recover.cpp:447] Starting replica recovery
I0116 02:37:51.245182 31524 recover.cpp:473] Replica is in EMPTY status
I0116 02:37:51.246217 31527 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13779)@172.17.0.5:34300
I0116 02:37:51.246937 31531 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0116 02:37:51.247371 31528 recover.cpp:564] Updating replica status to STARTING
I0116 02:37:51.248034 31530 master.cpp:374] Master d81ae6c0-98a1-485d-a64c-b550b615dce2 (a7f7c3769076) started on 172.17.0.5:34300
I0116 02:37:51.248059 31530 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/qiIrJq/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/qiIrJq/master" --zk_session_timeout="10secs"
I0116 02:37:51.248335 31530 master.cpp:423] Master allowing unauthenticated frameworks to register
I0116 02:37:51.248347 31530 master.cpp:426] Master only allowing authenticated slaves to register
I0116 02:37:51.248353 31530 credentials.hpp:35] Loading credentials for authentication from '/tmp/qiIrJq/credentials'
I0116 02:37:51.248658 31530 master.cpp:466] Using default 'crammd5' authenticator
I0116 02:37:51.248792 31530 master.cpp:535] Using default 'basic' HTTP authenticator
I0116 02:37:51.248905 31530 master.cpp:569] Authorization enabled
I0116 02:37:51.249079 31537 whitelist_watcher.cpp:77] No whitelist given
I0116 02:37:51.249091 31536 hierarchical.cpp:145] Initialized hierarchical allocator process
I0116 02:37:51.250777 31530 master.cpp:1710] The newly elected leader is master@172.17.0.5:34300 with id d81ae6c0-98a1-485d-a64c-b550b615dce2
I0116 02:37:51.250808 31530 master.cpp:1723] Elected as the leading master!
I0116 02:37:51.250823 31530 master.cpp:1468] Recovering from registrar
I0116 02:37:51.250982 31536 registrar.cpp:307] Recovering registrar
I0116 02:37:51.268770 31524 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 21.222086ms
I0116 02:37:51.268807 31524 replica.cpp:320] Persisted replica status to STARTING
I0116 02:37:51.269038 31526 recover.cpp:473] Replica is in STARTING status
I0116 02:37:51.270242 31524 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13781)@172.17.0.5:34300
I0116 02:37:51.270552 31537 recover.cpp:193] Received a recover response from a replica in STARTING status
I0116 02:37:51.271105 31534 recover.cpp:564] Updating replica status to VOTING
I0116 02:37:51.294672 31524 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 23.347361ms
I0116 02:37:51.294699 31524 replica.cpp:320] Persisted replica status to VOTING
I0116 02:37:51.294808 31533 recover.cpp:578] Successfully joined the Paxos group
I0116 02:37:51.295017 31533 recover.cpp:462] Recover process terminated
I0116 02:37:51.295441 31528 log.cpp:659] Attempting to start the writer
I0116 02:37:51.297062 31528 replica.cpp:493] Replica received implicit promise request from (13782)@172.17.0.5:34300 with proposal 1
I0116 02:37:51.319762 31528 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.656671ms
I0116 02:37:51.319798 31528 replica.cpp:342] Persisted promised to 1
I0116 02:37:51.320525 31533 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0116 02:37:51.322244 31534 replica.cpp:388] Replica received explicit promise request from (13783)@172.17.0.5:34300 for position 0 with proposal 2
I0116 02:37:51.344923 31534 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.621055ms
I0116 02:37:51.344965 31534 replica.cpp:712] Persisted action at 0
I0116 02:37:51.346354 31538 replica.cpp:537] Replica received write request for position 0 from (13784)@172.17.0.5:34300
I0116 02:37:51.346416 31538 leveldb.cpp:436] Reading position from leveldb took 30198ns
I0116 02:37:51.373330 31538 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 26.870825ms
I0116 02:37:51.373371 31538 replica.cpp:712] Persisted action at 0
I0116 02:37:51.374084 31529 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0116 02:37:51.398396 31529 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.275526ms
I0116 02:37:51.398427 31529 replica.cpp:712] Persisted action at 0
I0116 02:37:51.398444 31529 replica.cpp:697] Replica learned NOP action at position 0
I0116 02:37:51.399159 31536 log.cpp:675] Writer started with ending position 0
I0116 02:37:51.400470 31527 leveldb.cpp:436] Reading position from leveldb took 34469ns
I0116 02:37:51.401532 31537 registrar.cpp:340] Successfully fetched the registry (0B) in 150.49088ms
I0116 02:37:51.401692 31537 registrar.cpp:439] Applied 1 operations in 34982ns; attempting to update the 'registry'
I0116 02:37:51.402554 31523 log.cpp:683] Attempting to append 170 bytes to the log
I0116 02:37:51.402742 31524 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0116 02:37:51.403728 31532 replica.cpp:537] Replica received write request for position 1 from (13785)@172.17.0.5:34300
I0116 02:37:51.431895 31532 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 28.121088ms
I0116 02:37:51.431933 31532 replica.cpp:712] Persisted action at 1
I0116 02:37:51.432888 31535 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0116 02:37:51.457096 31535 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.170924ms
I0116 02:37:51.457144 31535 replica.cpp:712] Persisted action at 1
I0116 02:37:51.457180 31535 replica.cpp:697] Replica learned APPEND action at position 1
I0116 02:37:51.458338 31538 registrar.cpp:484] Successfully updated the 'registry' in 56.568064ms
I0116 02:37:51.458520 31538 registrar.cpp:370] Successfully recovered registrar
I0116 02:37:51.458703 31529 log.cpp:702] Attempting to truncate the log to 1
I0116 02:37:51.458847 31530 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0116 02:37:51.459718 31531 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0116 02:37:51.459745 31526 hierarchical.cpp:163] Skipping recovery of hierarchical allocator: nothing to recover
I0116 02:37:51.460026 31531 replica.cpp:537] Replica received write request for position 2 from (13786)@172.17.0.5:34300
I0116 02:37:51.490587 31531 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 30.512075ms
I0116 02:37:51.490656 31531 replica.cpp:712] Persisted action at 2
I0116 02:37:51.491567 31531 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0116 02:37:51.523991 31531 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 32.356927ms
I0116 02:37:51.524071 31531 leveldb.cpp:399] Deleting ~1 keys from leveldb took 40459ns
I0116 02:37:51.524096 31531 replica.cpp:712] Persisted action at 2
I0116 02:37:51.524118 31531 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0116 02:37:51.531138 31504 scheduler.cpp:154] Version: 0.27.0
I0116 02:37:51.531819 31526 scheduler.cpp:236] New master detected at master@172.17.0.5:34300
I0116 02:37:51.533269 31537 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:34300
I0116 02:37:51.535223 31524 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0116 02:37:51.535773 31523 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:33132
I0116 02:37:51.535967 31523 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0116 02:37:51.536041 31523 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0116 02:37:51.536308 31523 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0116 02:37:51.536748 31529 hierarchical.cpp:257] Added framework d81ae6c0-98a1-485d-a64c-b550b615dce2-0000
I0116 02:37:51.536751 31533 master.hpp:1658] Sending heartbeat to d81ae6c0-98a1-485d-a64c-b550b615dce2-0000
I0116 02:37:51.536825 31529 hierarchical.cpp:1327] No resources available to allocate!
I0116 02:37:51.536862 31529 hierarchical.cpp:1421] No inverse offers to send out!
I0116 02:37:51.536960 31529 hierarchical.cpp:1077] Performed allocation for 0 slaves in 177572ns
I0116 02:37:51.537493 31528 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:34300
I0116 02:37:51.538019 31528 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:34300
I0116 02:37:51.538494 31536 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0116 02:37:51.538624 31538 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:34300
I0116 02:37:51.539916 31526 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0116 02:37:51.540227 31537 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:33133
I0116 02:37:51.540318 31537 master.cpp:2717] Processing REQUEST call for framework d81ae6c0-98a1-485d-a64c-b550b615dce2-0000 (default)
I0116 02:37:51.540474 31533 hierarchical.cpp:577] Received resource request from framework d81ae6c0-98a1-485d-a64c-b550b615dce2-0000
I0116 02:37:51.540771 31528 master.cpp:1025] Master terminating
I0116 02:37:51.541015 31535 hierarchical.cpp:318] Removed framework d81ae6c0-98a1-485d-a64c-b550b615dce2-0000
E0116 02:37:51.542376 31524 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (475 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0116 02:37:51.645705 31504 leveldb.cpp:174] Opened db in 97.070594ms
I0116 02:37:51.684634 31504 leveldb.cpp:181] Compacted db in 38.885051ms
I0116 02:37:51.684701 31504 leveldb.cpp:196] Created db iterator in 20025ns
I0116 02:37:51.684722 31504 leveldb.cpp:202] Seeked to beginning of db in 2155ns
I0116 02:37:51.684734 31504 leveldb.cpp:271] Iterated through 0 keys in the db in 260ns
I0116 02:37:51.684770 31504 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0116 02:37:51.685217 31531 recover.cpp:447] Starting replica recovery
I0116 02:37:51.685797 31531 recover.cpp:473] Replica is in EMPTY status
I0116 02:37:51.686936 31533 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13794)@172.17.0.5:34300
I0116 02:37:51.687389 31530 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0116 02:37:51.687949 31536 recover.cpp:564] Updating replica status to STARTING
I0116 02:37:51.688860 31534 master.cpp:374] Master 00a14a7b-9f5b-43f1-9c90-2d41628f1379 (a7f7c3769076) started on 172.17.0.5:34300
I0116 02:37:51.688891 31534 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/iwICuf/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/iwICuf/master" --zk_session_timeout="10secs"
I0116 02:37:51.689270 31534 master.cpp:423] Master allowing unauthenticated frameworks to register
I0116 02:37:51.689291 31534 master.cpp:426] Master only allowing authenticated slaves to register
I0116 02:37:51.689308 31534 credentials.hpp:35] Loading credentials for authentication from '/tmp/iwICuf/credentials'
I0116 02:37:51.689712 31534 master.cpp:466] Using default 'crammd5' authenticator
I0116 02:37:51.689885 31534 master.cpp:535] Using default 'basic' HTTP authenticator
I0116 02:37:51.690096 31534 master.cpp:569] Authorization enabled
I0116 02:37:51.690284 31532 hierarchical.cpp:145] Initialized hierarchical allocator process
I0116 02:37:51.690376 31528 whitelist_watcher.cpp:77] No whitelist given
I0116 02:37:51.692214 31525 master.cpp:1710] The newly elected leader is master@172.17.0.5:34300 with id 00a14a7b-9f5b-43f1-9c90-2d41628f1379
I0116 02:37:51.692257 31525 master.cpp:1723] Elected as the leading master!
I0116 02:37:51.692281 31525 master.cpp:1468] Recovering from registrar
I0116 02:37:51.692437 31524 registrar.cpp:307] Recovering registrar
I0116 02:37:51.721204 31523 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 33.051122ms
I0116 02:37:51.721278 31523 replica.cpp:320] Persisted replica status to STARTING
I0116 02:37:51.721587 31523 recover.cpp:473] Replica is in STARTING status
I0116 02:37:51.723155 31531 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13796)@172.17.0.5:34300
I0116 02:37:51.723655 31533 recover.cpp:193] Received a recover response from a replica in STARTING status
I0116 02:37:51.724200 31524 recover.cpp:564] Updating replica status to VOTING
I0116 02:37:51.752117 31535 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 27.720527ms
I0116 02:37:51.752154 31535 replica.cpp:320] Persisted replica status to VOTING
I0116 02:37:51.752274 31525 recover.cpp:578] Successfully joined the Paxos group
I0116 02:37:51.752472 31525 recover.cpp:462] Recover process terminated
I0116 02:37:51.752910 31532 log.cpp:659] Attempting to start the writer
I0116 02:37:51.754029 31537 replica.cpp:493] Replica received implicit promise request from (13797)@172.17.0.5:34300 with proposal 1
I0116 02:37:51.771430 31537 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 17.365028ms
I0116 02:37:51.771469 31537 replica.cpp:342] Persisted promised to 1
I0116 02:37:51.772179 31534 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0116 02:37:51.773270 31524 replica.cpp:388] Replica received explicit promise request from (13798)@172.17.0.5:34300 for position 0 with proposal 2
I0116 02:37:51.796576 31524 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 23.261725ms
I0116 02:37:51.796633 31524 replica.cpp:712] Persisted action at 0
I0116 02:37:51.797714 31528 replica.cpp:537] Replica received write request for position 0 from (13799)@172.17.0.5:34300
I0116 02:37:51.797790 31528 leveldb.cpp:436] Reading position from leveldb took 35757ns
I0116 02:37:51.833376 31528 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 35.530477ms
I0116 02:37:51.833416 31528 replica.cpp:712] Persisted action at 0
I0116 02:37:51.834290 31531 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0116 02:37:51.875268 31531 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.874654ms
I0116 02:37:51.875308 31531 replica.cpp:712] Persisted action at 0
I0116 02:37:51.875330 31531 replica.cpp:697] Replica learned NOP action at position 0
I0116 02:37:51.876047 31526 log.cpp:675] Writer started with ending position 0
I0116 02:37:51.877353 31535 leveldb.cpp:436] Reading position from leveldb took 35792ns
I0116 02:37:51.878506 31535 registrar.cpp:340] Successfully fetched the registry (0B) in 185.901824ms
I0116 02:37:51.878665 31535 registrar.cpp:439] Applied 1 operations in 40257ns; attempting to update the 'registry'
I0116 02:37:51.879556 31533 log.cpp:683] Attempting to append 170 bytes to the log
I0116 02:37:51.879711 31537 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0116 02:37:51.880513 31524 replica.cpp:537] Replica received write request for position 1 from (13800)@172.17.0.5:34300
I0116 02:37:51.925405 31524 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 44.840255ms
I0116 02:37:51.925446 31524 replica.cpp:712] Persisted action at 1
I0116 02:37:51.926244 31535 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0116 02:37:51.967289 31535 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 41.000905ms
I0116 02:37:51.967336 31535 replica.cpp:712] Persisted action at 1
I0116 02:37:51.967361 31535 replica.cpp:697] Replica learned APPEND action at position 1
I0116 02:37:51.968538 31538 registrar.cpp:484] Successfully updated the 'registry' in 89.785856ms
I0116 02:37:51.968722 31538 registrar.cpp:370] Successfully recovered registrar
I0116 02:37:51.968884 31523 log.cpp:702] Attempting to truncate the log to 1
I0116 02:37:51.969063 31536 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0116 02:37:51.969276 31531 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0116 02:37:51.969308 31532 hierarchical.cpp:163] Skipping recovery of hierarchical allocator: nothing to recover
I0116 02:37:51.970111 31525 replica.cpp:537] Replica received write request for position 2 from (13801)@172.17.0.5:34300
I0116 02:37:52.009027 31525 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.863609ms
I0116 02:37:52.009066 31525 replica.cpp:712] Persisted action at 2
I0116 02:37:52.009757 31523 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0116 02:37:52.051486 31523 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 41.689713ms
I0116 02:37:52.051566 31523 leveldb.cpp:399] Deleting ~1 keys from leveldb took 40239ns
I0116 02:37:52.051599 31523 replica.cpp:712] Persisted action at 2
I0116 02:37:52.051671 31523 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0116 02:37:52.060580 31504 scheduler.cpp:154] Version: 0.27.0
I0116 02:37:52.061282 31527 scheduler.cpp:236] New master detected at master@172.17.0.5:34300
I0116 02:37:52.062680 31523 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:34300
I0116 02:37:52.064996 31528 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0116 02:37:52.065508 31531 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:33134
I0116 02:37:52.065923 31531 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0116 02:37:52.065996 31531 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0116 02:37:52.066309 31531 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0116 02:37:52.066751 31536 hierarchical.cpp:257] Added framework 00a14a7b-9f5b-43f1-9c90-2d41628f1379-0000
I0116 02:37:52.066862 31536 hierarchical.cpp:1327] No resources available to allocate!
I0116 02:37:52.066907 31536 hierarchical.cpp:1421] No inverse offers to send out!
I0116 02:37:52.066931 31536 hierarchical.cpp:1077] Performed allocation for 0 slaves in 150517ns
I0116 02:37:52.066974 31536 master.hpp:1658] Sending heartbeat to 00a14a7b-9f5b-43f1-9c90-2d41628f1379-0000
I0116 02:37:52.067806 31535 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:34300
I0116 02:37:52.068316 31535 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:34300
I0116 02:37:52.069145 31530 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0116 02:37:52.069216 31535 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:34300
I0116 02:37:52.070819 31523 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0116 02:37:52.071290 31538 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:33135
I0116 02:37:52.071549 31538 master.cpp:2717] Processing REQUEST call for framework 00a14a7b-9f5b-43f1-9c90-2d41628f1379-0000 (default)
I0116 02:37:52.071765 31535 hierarchical.cpp:577] Received resource request from framework 00a14a7b-9f5b-43f1-9c90-2d41628f1379-0000
I0116 02:37:52.072094 31530 master.cpp:1025] Master terminating
I0116 02:37:52.072342 31523 hierarchical.cpp:318] Removed framework 00a14a7b-9f5b-43f1-9c90-2d41628f1379-0000
E0116 02:37:52.073938 31533 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (533 ms)
[----------] 22 tests from ContentType/SchedulerTest (15284 ms total)
[----------] Global test environment tear-down
[==========] 928 tests from 123 test cases ran. (732845 ms total)
[ PASSED ] 927 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ReservationTest.ReservationInfoNoPrincipal
1 FAILED TEST
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-1452909363-24230
Untagged: mesos-1452909363-24230:latest
Deleted: 550d62c792c76b950fd33ccb3be5a0a7ea360f8213fd4b1a403808f125f33514
Deleted: fea70ed0875a81397bd008329e56560cb49b5a6352ba4683e0224d823731ecda
Deleted: 2e7d040f0731187a9a4d274ec93737bd6e4391e8fa4b3d69858c5de28f8bb9f1
Deleted: c704443de5e8b836598544a065d3e194378f3bec8e6964cac4e3fec3991880b1
Deleted: f603c0c9b673eed06c490f70ed037d430baf524d5a5fa83e3a6e119dc2f9f6a0
Deleted: c24da201d7856204f4c11752e96ccc2f9f0f420238cf9243ef028d69c3287278
Deleted: 7c9225cf3fab6c657aec673604850c403585cc461a719788af46a626262c6bbf
Deleted: 783fd1971a2c98f579707912f5d3163d8e36cef84ff54fcf132915173d940f62
Deleted: 8413938a0078f8425c976dd5d413401c3f83025913ff1fff2043887d8bddbd0b
Deleted: 1d3ee861af329f6c2288abc623a0e07064c93061808f6b30a6ba3d048755cac6
Deleted: 71b799a8102a3d7bbd2776d5bcc61b0da310a6d23920b7496f57f3c54557eb75
Deleted: 198e5cf5d20289469ebab7c3c1eeeac503bbd109694a99bc511f730b61537e05
Deleted: c3220f8d2bf4bc03ff0d1e12d0125f1b2b7eed298af2b37d94b13aa06dba05c1
Deleted: f68b582b02876a478bfa4e9e2490963c93ccf017d662212f8128a36bc35fb805
Error handling URL https://reviews.apache.org/api/review-requests/42361/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard c8c4901b2d7fad7347c67a0cc155cf281c4f2c24
Build step 'Execute shell' marked build as failure