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/03 09:00:24 UTC

Build failed in Jenkins: mesos-reviewbot #10530

See <https://builds.apache.org/job/mesos-reviewbot/10530/>

------------------------------------------
[...truncated 165361 lines...]
[       OK ] ContentType/SchedulerTest.Message/1 (626 ms)
[ RUN      ] ContentType/SchedulerTest.Request/0
I0103 08:00:07.958400 31023 leveldb.cpp:174] Opened db in 191.416532ms
I0103 08:00:08.167613 31023 leveldb.cpp:181] Compacted db in 209.145984ms
I0103 08:00:08.167717 31023 leveldb.cpp:196] Created db iterator in 28212ns
I0103 08:00:08.167737 31023 leveldb.cpp:202] Seeked to beginning of db in 3363ns
I0103 08:00:08.167747 31023 leveldb.cpp:271] Iterated through 0 keys in the db in 297ns
I0103 08:00:08.167798 31023 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0103 08:00:08.168346 31044 recover.cpp:447] Starting replica recovery
I0103 08:00:08.168570 31044 recover.cpp:473] Replica is in EMPTY status
I0103 08:00:08.169728 31057 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12827)@172.17.0.5:45435
I0103 08:00:08.170269 31050 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0103 08:00:08.170737 31051 recover.cpp:564] Updating replica status to STARTING
I0103 08:00:08.171924 31055 master.cpp:365] Master f9d0d569-02cb-4420-8ba5-d57d4f3c61c4 (b78012871317) started on 172.17.0.5:45435
I0103 08:00:08.171967 31055 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/GS2GMh/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/GS2GMh/master" --zk_session_timeout="10secs"
I0103 08:00:08.172229 31055 master.cpp:414] Master allowing unauthenticated frameworks to register
I0103 08:00:08.172245 31055 master.cpp:417] Master only allowing authenticated slaves to register
I0103 08:00:08.172258 31055 credentials.hpp:35] Loading credentials for authentication from '/tmp/GS2GMh/credentials'
I0103 08:00:08.172518 31055 master.cpp:456] Using default 'crammd5' authenticator
I0103 08:00:08.172688 31055 master.cpp:493] Authorization enabled
I0103 08:00:08.172842 31048 hierarchical.cpp:147] Initialized hierarchical allocator process
I0103 08:00:08.172869 31056 whitelist_watcher.cpp:77] No whitelist given
I0103 08:00:08.174540 31050 master.cpp:1629] The newly elected leader is master@172.17.0.5:45435 with id f9d0d569-02cb-4420-8ba5-d57d4f3c61c4
I0103 08:00:08.174573 31050 master.cpp:1642] Elected as the leading master!
I0103 08:00:08.174595 31050 master.cpp:1387] Recovering from registrar
I0103 08:00:08.174783 31053 registrar.cpp:307] Recovering registrar
I0103 08:00:08.202488 31043 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.552205ms
I0103 08:00:08.202545 31043 replica.cpp:320] Persisted replica status to STARTING
I0103 08:00:08.202849 31056 recover.cpp:473] Replica is in STARTING status
I0103 08:00:08.203860 31056 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12828)@172.17.0.5:45435
I0103 08:00:08.204278 31052 recover.cpp:193] Received a recover response from a replica in STARTING status
I0103 08:00:08.204777 31044 recover.cpp:564] Updating replica status to VOTING
I0103 08:00:08.227705 31049 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.751706ms
I0103 08:00:08.227747 31049 replica.cpp:320] Persisted replica status to VOTING
I0103 08:00:08.227877 31057 recover.cpp:578] Successfully joined the Paxos group
I0103 08:00:08.228119 31057 recover.cpp:462] Recover process terminated
I0103 08:00:08.228662 31043 log.cpp:659] Attempting to start the writer
I0103 08:00:08.229955 31049 replica.cpp:493] Replica received implicit promise request from (12829)@172.17.0.5:45435 with proposal 1
I0103 08:00:08.252713 31049 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.721653ms
I0103 08:00:08.252758 31049 replica.cpp:342] Persisted promised to 1
I0103 08:00:08.253440 31045 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0103 08:00:08.255167 31051 replica.cpp:388] Replica received explicit promise request from (12830)@172.17.0.5:45435 for position 0 with proposal 2
I0103 08:00:08.277834 31051 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.586964ms
I0103 08:00:08.277883 31051 replica.cpp:712] Persisted action at 0
I0103 08:00:08.279183 31046 replica.cpp:537] Replica received write request for position 0 from (12831)@172.17.0.5:45435
I0103 08:00:08.279263 31046 leveldb.cpp:436] Reading position from leveldb took 37111ns
I0103 08:00:08.302904 31046 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.590959ms
I0103 08:00:08.302942 31046 replica.cpp:712] Persisted action at 0
I0103 08:00:08.303772 31048 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0103 08:00:08.328032 31048 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.161587ms
I0103 08:00:08.328073 31048 replica.cpp:712] Persisted action at 0
I0103 08:00:08.328094 31048 replica.cpp:697] Replica learned NOP action at position 0
I0103 08:00:08.328840 31053 log.cpp:675] Writer started with ending position 0
I0103 08:00:08.330284 31052 leveldb.cpp:436] Reading position from leveldb took 34151ns
I0103 08:00:08.331452 31048 registrar.cpp:340] Successfully fetched the registry (0B) in 156.617984ms
I0103 08:00:08.331620 31048 registrar.cpp:439] Applied 1 operations in 43934ns; attempting to update the 'registry'
I0103 08:00:08.332567 31047 log.cpp:683] Attempting to append 170 bytes to the log
I0103 08:00:08.332779 31045 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0103 08:00:08.333642 31053 replica.cpp:537] Replica received write request for position 1 from (12832)@172.17.0.5:45435
I0103 08:00:08.359645 31053 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 25.94942ms
I0103 08:00:08.359684 31053 replica.cpp:712] Persisted action at 1
I0103 08:00:08.360492 31051 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0103 08:00:08.391893 31051 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 31.362483ms
I0103 08:00:08.391945 31051 replica.cpp:712] Persisted action at 1
I0103 08:00:08.391983 31051 replica.cpp:697] Replica learned APPEND action at position 1
I0103 08:00:08.393196 31046 registrar.cpp:484] Successfully updated the 'registry' in 61.50272ms
I0103 08:00:08.393399 31046 registrar.cpp:370] Successfully recovered registrar
I0103 08:00:08.393493 31055 log.cpp:702] Attempting to truncate the log to 1
I0103 08:00:08.393771 31053 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0103 08:00:08.394129 31043 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0103 08:00:08.394170 31050 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0103 08:00:08.394958 31054 replica.cpp:537] Replica received write request for position 2 from (12833)@172.17.0.5:45435
I0103 08:00:08.433662 31054 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.659143ms
I0103 08:00:08.433706 31054 replica.cpp:712] Persisted action at 2
I0103 08:00:08.434432 31056 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0103 08:00:08.467104 31056 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 32.632467ms
I0103 08:00:08.467185 31056 leveldb.cpp:399] Deleting ~1 keys from leveldb took 40718ns
I0103 08:00:08.467211 31056 replica.cpp:712] Persisted action at 2
I0103 08:00:08.467233 31056 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0103 08:00:08.476002 31023 scheduler.cpp:154] Version: 0.27.0
I0103 08:00:08.476685 31048 scheduler.cpp:236] New master detected at master@172.17.0.5:45435
I0103 08:00:08.477668 31047 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:45435
I0103 08:00:08.479421 31053 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 08:00:08.479874 31046 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:53395
I0103 08:00:08.480044 31046 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0103 08:00:08.480103 31046 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0103 08:00:08.480331 31046 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [  ]
I0103 08:00:08.480762 31054 hierarchical.cpp:260] Added framework f9d0d569-02cb-4420-8ba5-d57d4f3c61c4-0000
I0103 08:00:08.480828 31056 master.hpp:1659] Sending heartbeat to f9d0d569-02cb-4420-8ba5-d57d4f3c61c4-0000
I0103 08:00:08.480927 31054 hierarchical.cpp:1329] No resources available to allocate!
I0103 08:00:08.480965 31054 hierarchical.cpp:1423] No inverse offers to send out!
I0103 08:00:08.481001 31054 hierarchical.cpp:1079] Performed allocation for 0 slaves in 134993ns
I0103 08:00:08.481798 31052 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:45435
I0103 08:00:08.482305 31052 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:45435
I0103 08:00:08.483131 31053 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0103 08:00:08.483245 31052 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:45435
I0103 08:00:08.485139 31046 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 08:00:08.485666 31044 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:53396
I0103 08:00:08.485797 31044 master.cpp:2636] Processing REQUEST call for framework f9d0d569-02cb-4420-8ba5-d57d4f3c61c4-0000 (default)
I0103 08:00:08.486009 31047 hierarchical.cpp:579] Received resource request from framework f9d0d569-02cb-4420-8ba5-d57d4f3c61c4-0000
I0103 08:00:08.486296 31048 master.cpp:930] Master terminating
I0103 08:00:08.486542 31042 hierarchical.cpp:321] Removed framework f9d0d569-02cb-4420-8ba5-d57d4f3c61c4-0000
E0103 08:00:08.487849 31043 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[       OK ] ContentType/SchedulerTest.Request/0 (727 ms)
[ RUN      ] ContentType/SchedulerTest.Request/1
I0103 08:00:08.610317 31023 leveldb.cpp:174] Opened db in 115.891089ms
I0103 08:00:08.660559 31023 leveldb.cpp:181] Compacted db in 50.197707ms
I0103 08:00:08.660645 31023 leveldb.cpp:196] Created db iterator in 44839ns
I0103 08:00:08.660667 31023 leveldb.cpp:202] Seeked to beginning of db in 2015ns
I0103 08:00:08.660678 31023 leveldb.cpp:271] Iterated through 0 keys in the db in 412ns
I0103 08:00:08.660718 31023 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0103 08:00:08.661274 31046 recover.cpp:447] Starting replica recovery
I0103 08:00:08.661640 31046 recover.cpp:473] Replica is in EMPTY status
I0103 08:00:08.662685 31046 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12841)@172.17.0.5:45435
I0103 08:00:08.663106 31055 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0103 08:00:08.663472 31045 recover.cpp:564] Updating replica status to STARTING
I0103 08:00:08.664139 31052 master.cpp:365] Master ea0e792e-5701-4e89-98f4-a00a14fd73c8 (b78012871317) started on 172.17.0.5:45435
I0103 08:00:08.664161 31052 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/vmIYYV/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/vmIYYV/master" --zk_session_timeout="10secs"
I0103 08:00:08.664408 31052 master.cpp:414] Master allowing unauthenticated frameworks to register
I0103 08:00:08.664420 31052 master.cpp:417] Master only allowing authenticated slaves to register
I0103 08:00:08.664427 31052 credentials.hpp:35] Loading credentials for authentication from '/tmp/vmIYYV/credentials'
I0103 08:00:08.664651 31052 master.cpp:456] Using default 'crammd5' authenticator
I0103 08:00:08.664759 31052 master.cpp:493] Authorization enabled
I0103 08:00:08.664911 31044 hierarchical.cpp:147] Initialized hierarchical allocator process
I0103 08:00:08.664937 31053 whitelist_watcher.cpp:77] No whitelist given
I0103 08:00:08.666646 31046 master.cpp:1629] The newly elected leader is master@172.17.0.5:45435 with id ea0e792e-5701-4e89-98f4-a00a14fd73c8
I0103 08:00:08.666683 31046 master.cpp:1642] Elected as the leading master!
I0103 08:00:08.666702 31046 master.cpp:1387] Recovering from registrar
I0103 08:00:08.666851 31048 registrar.cpp:307] Recovering registrar
I0103 08:00:08.695274 31057 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.684859ms
I0103 08:00:08.695322 31057 replica.cpp:320] Persisted replica status to STARTING
I0103 08:00:08.695554 31057 recover.cpp:473] Replica is in STARTING status
I0103 08:00:08.696557 31046 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12842)@172.17.0.5:45435
I0103 08:00:08.696779 31047 recover.cpp:193] Received a recover response from a replica in STARTING status
I0103 08:00:08.697190 31057 recover.cpp:564] Updating replica status to VOTING
I0103 08:00:08.737790 31048 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 40.455171ms
I0103 08:00:08.737889 31048 replica.cpp:320] Persisted replica status to VOTING
I0103 08:00:08.738149 31051 recover.cpp:578] Successfully joined the Paxos group
I0103 08:00:08.738400 31051 recover.cpp:462] Recover process terminated
I0103 08:00:08.739013 31055 log.cpp:659] Attempting to start the writer
I0103 08:00:08.740310 31056 replica.cpp:493] Replica received implicit promise request from (12843)@172.17.0.5:45435 with proposal 1
I0103 08:00:08.778928 31056 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 38.561094ms
I0103 08:00:08.779011 31056 replica.cpp:342] Persisted promised to 1
I0103 08:00:08.779819 31043 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0103 08:00:08.781096 31043 replica.cpp:388] Replica received explicit promise request from (12844)@172.17.0.5:45435 for position 0 with proposal 2
I0103 08:00:08.820572 31043 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 39.419219ms
I0103 08:00:08.820711 31043 replica.cpp:712] Persisted action at 0
I0103 08:00:08.821876 31056 replica.cpp:537] Replica received write request for position 0 from (12845)@172.17.0.5:45435
I0103 08:00:08.821951 31056 leveldb.cpp:436] Reading position from leveldb took 38386ns
I0103 08:00:08.862565 31056 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.557047ms
I0103 08:00:08.862701 31056 replica.cpp:712] Persisted action at 0
I0103 08:00:08.863461 31049 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0103 08:00:08.904299 31049 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.796594ms
I0103 08:00:08.904364 31049 replica.cpp:712] Persisted action at 0
I0103 08:00:08.904391 31049 replica.cpp:697] Replica learned NOP action at position 0
I0103 08:00:08.905117 31044 log.cpp:675] Writer started with ending position 0
I0103 08:00:08.906714 31054 leveldb.cpp:436] Reading position from leveldb took 69056ns
I0103 08:00:08.907791 31057 registrar.cpp:340] Successfully fetched the registry (0B) in 240.88704ms
I0103 08:00:08.907919 31057 registrar.cpp:439] Applied 1 operations in 35855ns; attempting to update the 'registry'
I0103 08:00:08.908639 31049 log.cpp:683] Attempting to append 170 bytes to the log
I0103 08:00:08.908787 31043 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0103 08:00:08.909498 31055 replica.cpp:537] Replica received write request for position 1 from (12846)@172.17.0.5:45435
I0103 08:00:08.946055 31055 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 36.517125ms
I0103 08:00:08.946095 31055 replica.cpp:712] Persisted action at 1
I0103 08:00:08.946826 31050 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0103 08:00:08.987946 31050 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 41.085233ms
I0103 08:00:08.987993 31050 replica.cpp:712] Persisted action at 1
I0103 08:00:08.988018 31050 replica.cpp:697] Replica learned APPEND action at position 1
I0103 08:00:08.989183 31055 registrar.cpp:484] Successfully updated the 'registry' in 81.19424ms
I0103 08:00:08.989380 31055 registrar.cpp:370] Successfully recovered registrar
I0103 08:00:08.989667 31048 log.cpp:702] Attempting to truncate the log to 1
I0103 08:00:08.989809 31047 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0103 08:00:08.990200 31043 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0103 08:00:08.990288 31056 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0103 08:00:08.990803 31042 replica.cpp:537] Replica received write request for position 2 from (12847)@172.17.0.5:45435
I0103 08:00:09.029706 31042 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.857357ms
I0103 08:00:09.029750 31042 replica.cpp:712] Persisted action at 2
I0103 08:00:09.030525 31055 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0103 08:00:09.071470 31055 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 40.901572ms
I0103 08:00:09.071553 31055 leveldb.cpp:399] Deleting ~1 keys from leveldb took 43276ns
I0103 08:00:09.071589 31055 replica.cpp:712] Persisted action at 2
I0103 08:00:09.071638 31055 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0103 08:00:09.081853 31023 scheduler.cpp:154] Version: 0.27.0
I0103 08:00:09.082952 31051 scheduler.cpp:236] New master detected at master@172.17.0.5:45435
I0103 08:00:09.084180 31050 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:45435
I0103 08:00:09.086302 31056 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 08:00:09.086869 31045 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:53397
I0103 08:00:09.087235 31045 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0103 08:00:09.087319 31045 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0103 08:00:09.087678 31045 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [  ]
I0103 08:00:09.088089 31042 hierarchical.cpp:260] Added framework ea0e792e-5701-4e89-98f4-a00a14fd73c8-0000
I0103 08:00:09.088155 31042 hierarchical.cpp:1329] No resources available to allocate!
I0103 08:00:09.088186 31042 hierarchical.cpp:1423] No inverse offers to send out!
I0103 08:00:09.088207 31051 master.hpp:1659] Sending heartbeat to ea0e792e-5701-4e89-98f4-a00a14fd73c8-0000
I0103 08:00:09.088208 31042 hierarchical.cpp:1079] Performed allocation for 0 slaves in 93953ns
I0103 08:00:09.089041 31046 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:45435
I0103 08:00:09.089596 31046 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:45435
I0103 08:00:09.090219 31055 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0103 08:00:09.090291 31046 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:45435
I0103 08:00:09.091850 31051 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 08:00:09.092218 31042 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:53398
I0103 08:00:09.092455 31042 master.cpp:2636] Processing REQUEST call for framework ea0e792e-5701-4e89-98f4-a00a14fd73c8-0000 (default)
I0103 08:00:09.092686 31055 hierarchical.cpp:579] Received resource request from framework ea0e792e-5701-4e89-98f4-a00a14fd73c8-0000
I0103 08:00:09.093042 31043 master.cpp:930] Master terminating
I0103 08:00:09.093273 31045 hierarchical.cpp:321] Removed framework ea0e792e-5701-4e89-98f4-a00a14fd73c8-0000
E0103 08:00:09.094825 31047 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[       OK ] ContentType/SchedulerTest.Request/1 (607 ms)
[----------] 22 tests from ContentType/SchedulerTest (15644 ms total)

[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (733194 ms total)
[  PASSED  ] 913 tests.
[  FAILED  ] 2 tests, listed below:
[  FAILED  ] ProvisionerDockerLocalStoreTest.LocalStoreTestWithTar
[  FAILED  ] ProvisionerDockerLocalStoreTest.MetadataManagerInitialization

 2 FAILED TESTS
  YOU HAVE 6 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]: Leaving directory `/mesos/mesos-0.27.0/_build'
make[1]: *** [check-recursive] Error 1
make: *** [distcheck] Error 1
+ docker rmi mesos-1451805581-18682
Untagged: mesos-1451805581-18682:latest
Deleted: 70f1eb252c32f8d11b5b5247043c6ada607be4d5b46efab1c610dd7dc28d95a2
Deleted: 89eaeb7751883c6618368f18c6cb46047ecdf83f2abeafb901aba3279a2591c6
Deleted: 43dda9d6cc094349336bd2d2ca4391a3066c4ba9db408cd61e8e42aa5e243c11
Deleted: 1f4b772c453785bfab452bb9a67386fabf319310dce939ef6bba36991db98b23
Deleted: 9c9ac7065022d249381f1286be781f0d9dae33ce37e762448e7f22ea441d29df
Deleted: 19cadc96ab3b129828ba2f4f6ff96fd02f2f1843ab039935cab8b0cd89a2499f
Deleted: 754cfeda366d1f9a73c4cb96464bd0a7afae5fdcdc36658bc333ab16b26ef5cc
Deleted: 1e7e9e84509fb32c635d4eead5fc3fc7a075eb8a2c439b500158160253f3b74f
Deleted: 6ace36d52803e29b195e151b7de77e2aad5fadfe5ba9d70225a5e8eaf11f6efb
Deleted: 3789dd283246c87b16cc4e0421bcc24da8c69a8a674754df6af1533fe972febe
Deleted: 6909fa490b8a8a5e5643f2f53be8c96dae7c3bf8be17cfaeb9aa4b1a6771d563
Deleted: 535767f52afd7828730daf2d503e88ab908699148285d16f5b75faf1801e1d73
Deleted: a67ec3ec0ee77e8fa5226aebfc57ac3b3460fe3d06361e50fb1f9bcec0c9c00b

Error handling URL https://reviews.apache.org/api/review-requests/41731/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard f05eb74b905ebb1eec2db0b694e2ff0c34413d26

Build step 'Execute shell' marked build as failure

Jenkins build is back to normal : mesos-reviewbot #10533

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10533/>


Build failed in Jenkins: mesos-reviewbot #10532

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10532/>

------------------------------------------
[...truncated 165444 lines...]
[       OK ] ContentType/SchedulerTest.Message/1 (785 ms)
[ RUN      ] ContentType/SchedulerTest.Request/0
I0103 10:06:23.399935 31012 leveldb.cpp:174] Opened db in 138.142122ms
I0103 10:06:23.458582 31012 leveldb.cpp:181] Compacted db in 58.604527ms
I0103 10:06:23.458675 31012 leveldb.cpp:196] Created db iterator in 18895ns
I0103 10:06:23.458694 31012 leveldb.cpp:202] Seeked to beginning of db in 1975ns
I0103 10:06:23.458706 31012 leveldb.cpp:271] Iterated through 0 keys in the db in 343ns
I0103 10:06:23.458745 31012 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0103 10:06:23.460086 31042 recover.cpp:447] Starting replica recovery
I0103 10:06:23.460353 31042 recover.cpp:473] Replica is in EMPTY status
I0103 10:06:23.461437 31041 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12846)@172.17.0.5:36256
I0103 10:06:23.461918 31039 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0103 10:06:23.462419 31046 master.cpp:365] Master 8fb0621a-61a9-46fc-98e8-a3b0ea626dd8 (faa43f3fe7be) started on 172.17.0.5:36256
I0103 10:06:23.462528 31042 recover.cpp:564] Updating replica status to STARTING
I0103 10:06:23.462451 31046 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/Zs4hFS/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/Zs4hFS/master" --zk_session_timeout="10secs"
I0103 10:06:23.462857 31046 master.cpp:414] Master allowing unauthenticated frameworks to register
I0103 10:06:23.462877 31046 master.cpp:417] Master only allowing authenticated slaves to register
I0103 10:06:23.462889 31046 credentials.hpp:35] Loading credentials for authentication from '/tmp/Zs4hFS/credentials'
I0103 10:06:23.463150 31046 master.cpp:456] Using default 'crammd5' authenticator
I0103 10:06:23.463268 31046 master.cpp:493] Authorization enabled
I0103 10:06:23.463420 31040 hierarchical.cpp:147] Initialized hierarchical allocator process
I0103 10:06:23.463435 31033 whitelist_watcher.cpp:77] No whitelist given
I0103 10:06:23.464854 31043 master.cpp:1629] The newly elected leader is master@172.17.0.5:36256 with id 8fb0621a-61a9-46fc-98e8-a3b0ea626dd8
I0103 10:06:23.464895 31043 master.cpp:1642] Elected as the leading master!
I0103 10:06:23.464922 31043 master.cpp:1387] Recovering from registrar
I0103 10:06:23.465106 31038 registrar.cpp:307] Recovering registrar
I0103 10:06:23.484159 31037 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 21.375564ms
I0103 10:06:23.484203 31037 replica.cpp:320] Persisted replica status to STARTING
I0103 10:06:23.484447 31034 recover.cpp:473] Replica is in STARTING status
I0103 10:06:23.485379 31045 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12847)@172.17.0.5:36256
I0103 10:06:23.485647 31031 recover.cpp:193] Received a recover response from a replica in STARTING status
I0103 10:06:23.485996 31043 recover.cpp:564] Updating replica status to VOTING
I0103 10:06:23.509169 31041 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 23.03954ms
I0103 10:06:23.509197 31041 replica.cpp:320] Persisted replica status to VOTING
I0103 10:06:23.509296 31034 recover.cpp:578] Successfully joined the Paxos group
I0103 10:06:23.509503 31034 recover.cpp:462] Recover process terminated
I0103 10:06:23.509994 31044 log.cpp:659] Attempting to start the writer
I0103 10:06:23.511304 31035 replica.cpp:493] Replica received implicit promise request from (12848)@172.17.0.5:36256 with proposal 1
I0103 10:06:23.534361 31035 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 23.017577ms
I0103 10:06:23.534400 31035 replica.cpp:342] Persisted promised to 1
I0103 10:06:23.535095 31034 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0103 10:06:23.536370 31035 replica.cpp:388] Replica received explicit promise request from (12849)@172.17.0.5:36256 for position 0 with proposal 2
I0103 10:06:23.559478 31035 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 23.056301ms
I0103 10:06:23.559517 31035 replica.cpp:712] Persisted action at 0
I0103 10:06:23.560896 31042 replica.cpp:537] Replica received write request for position 0 from (12850)@172.17.0.5:36256
I0103 10:06:23.560974 31042 leveldb.cpp:436] Reading position from leveldb took 34662ns
I0103 10:06:23.584632 31042 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.576699ms
I0103 10:06:23.584674 31042 replica.cpp:712] Persisted action at 0
I0103 10:06:23.585398 31044 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0103 10:06:23.609644 31044 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.204414ms
I0103 10:06:23.609685 31044 replica.cpp:712] Persisted action at 0
I0103 10:06:23.609707 31044 replica.cpp:697] Replica learned NOP action at position 0
I0103 10:06:23.610385 31046 log.cpp:675] Writer started with ending position 0
I0103 10:06:23.611520 31031 leveldb.cpp:436] Reading position from leveldb took 33331ns
I0103 10:06:23.612584 31036 registrar.cpp:340] Successfully fetched the registry (0B) in 147.428864ms
I0103 10:06:23.612746 31036 registrar.cpp:439] Applied 1 operations in 26045ns; attempting to update the 'registry'
I0103 10:06:23.613477 31033 log.cpp:683] Attempting to append 170 bytes to the log
I0103 10:06:23.613697 31036 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0103 10:06:23.614470 31044 replica.cpp:537] Replica received write request for position 1 from (12851)@172.17.0.5:36256
I0103 10:06:23.634748 31044 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 20.234109ms
I0103 10:06:23.634788 31044 replica.cpp:712] Persisted action at 1
I0103 10:06:23.635648 31043 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0103 10:06:23.659863 31043 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.176989ms
I0103 10:06:23.659903 31043 replica.cpp:712] Persisted action at 1
I0103 10:06:23.659925 31043 replica.cpp:697] Replica learned APPEND action at position 1
I0103 10:06:23.661023 31037 registrar.cpp:484] Successfully updated the 'registry' in 48.2112ms
I0103 10:06:23.661173 31037 registrar.cpp:370] Successfully recovered registrar
I0103 10:06:23.661352 31046 log.cpp:702] Attempting to truncate the log to 1
I0103 10:06:23.661594 31032 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0103 10:06:23.661802 31036 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0103 10:06:23.661864 31038 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0103 10:06:23.662566 31042 replica.cpp:537] Replica received write request for position 2 from (12852)@172.17.0.5:36256
I0103 10:06:23.692401 31042 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 29.758908ms
I0103 10:06:23.692440 31042 replica.cpp:712] Persisted action at 2
I0103 10:06:23.693146 31046 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0103 10:06:23.734133 31046 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 40.895971ms
I0103 10:06:23.734215 31046 leveldb.cpp:399] Deleting ~1 keys from leveldb took 42497ns
I0103 10:06:23.734249 31046 replica.cpp:712] Persisted action at 2
I0103 10:06:23.734273 31046 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0103 10:06:23.742905 31012 scheduler.cpp:154] Version: 0.27.0
I0103 10:06:23.743630 31038 scheduler.cpp:236] New master detected at master@172.17.0.5:36256
I0103 10:06:23.744801 31037 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:36256
I0103 10:06:23.746687 31034 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 10:06:23.747359 31040 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:35765
I0103 10:06:23.747582 31040 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0103 10:06:23.747675 31040 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0103 10:06:23.748029 31040 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [  ]
I0103 10:06:23.748438 31034 hierarchical.cpp:260] Added framework 8fb0621a-61a9-46fc-98e8-a3b0ea626dd8-0000
I0103 10:06:23.748514 31034 hierarchical.cpp:1329] No resources available to allocate!
I0103 10:06:23.748500 31044 master.hpp:1659] Sending heartbeat to 8fb0621a-61a9-46fc-98e8-a3b0ea626dd8-0000
I0103 10:06:23.748675 31034 hierarchical.cpp:1423] No inverse offers to send out!
I0103 10:06:23.748716 31034 hierarchical.cpp:1079] Performed allocation for 0 slaves in 241349ns
I0103 10:06:23.749495 31037 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:36256
I0103 10:06:23.750072 31037 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:36256
I0103 10:06:23.750870 31038 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0103 10:06:23.750933 31037 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:36256
I0103 10:06:23.752663 31034 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 10:06:23.753125 31044 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:35766
I0103 10:06:23.753257 31044 master.cpp:2636] Processing REQUEST call for framework 8fb0621a-61a9-46fc-98e8-a3b0ea626dd8-0000 (default)
I0103 10:06:23.753456 31039 hierarchical.cpp:579] Received resource request from framework 8fb0621a-61a9-46fc-98e8-a3b0ea626dd8-0000
I0103 10:06:23.753783 31034 master.cpp:930] Master terminating
I0103 10:06:23.753998 31039 hierarchical.cpp:321] Removed framework 8fb0621a-61a9-46fc-98e8-a3b0ea626dd8-0000
E0103 10:06:23.755105 31042 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[       OK ] ContentType/SchedulerTest.Request/0 (500 ms)
[ RUN      ] ContentType/SchedulerTest.Request/1
I0103 10:06:23.844879 31012 leveldb.cpp:174] Opened db in 82.713294ms
I0103 10:06:23.874131 31012 leveldb.cpp:181] Compacted db in 29.209999ms
I0103 10:06:23.874196 31012 leveldb.cpp:196] Created db iterator in 17804ns
I0103 10:06:23.874215 31012 leveldb.cpp:202] Seeked to beginning of db in 1975ns
I0103 10:06:23.874228 31012 leveldb.cpp:271] Iterated through 0 keys in the db in 325ns
I0103 10:06:23.874264 31012 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0103 10:06:23.874954 31033 recover.cpp:447] Starting replica recovery
I0103 10:06:23.875293 31033 recover.cpp:473] Replica is in EMPTY status
I0103 10:06:23.876361 31040 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12860)@172.17.0.5:36256
I0103 10:06:23.876725 31038 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0103 10:06:23.877341 31031 recover.cpp:564] Updating replica status to STARTING
I0103 10:06:23.878155 31035 master.cpp:365] Master ec5677a7-3657-4516-a9a2-2fb1676df5fd (faa43f3fe7be) started on 172.17.0.5:36256
I0103 10:06:23.878190 31035 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/NFbCoC/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/NFbCoC/master" --zk_session_timeout="10secs"
I0103 10:06:23.878520 31035 master.cpp:414] Master allowing unauthenticated frameworks to register
I0103 10:06:23.878535 31035 master.cpp:417] Master only allowing authenticated slaves to register
I0103 10:06:23.878545 31035 credentials.hpp:35] Loading credentials for authentication from '/tmp/NFbCoC/credentials'
I0103 10:06:23.878825 31035 master.cpp:456] Using default 'crammd5' authenticator
I0103 10:06:23.878954 31035 master.cpp:493] Authorization enabled
I0103 10:06:23.879109 31033 whitelist_watcher.cpp:77] No whitelist given
I0103 10:06:23.879122 31045 hierarchical.cpp:147] Initialized hierarchical allocator process
I0103 10:06:23.880945 31044 master.cpp:1629] The newly elected leader is master@172.17.0.5:36256 with id ec5677a7-3657-4516-a9a2-2fb1676df5fd
I0103 10:06:23.880985 31044 master.cpp:1642] Elected as the leading master!
I0103 10:06:23.881009 31044 master.cpp:1387] Recovering from registrar
I0103 10:06:23.881199 31039 registrar.cpp:307] Recovering registrar
I0103 10:06:23.918556 31032 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 40.990527ms
I0103 10:06:23.918634 31032 replica.cpp:320] Persisted replica status to STARTING
I0103 10:06:23.918969 31036 recover.cpp:473] Replica is in STARTING status
I0103 10:06:23.920362 31035 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12861)@172.17.0.5:36256
I0103 10:06:23.920655 31044 recover.cpp:193] Received a recover response from a replica in STARTING status
I0103 10:06:23.921221 31032 recover.cpp:564] Updating replica status to VOTING
I0103 10:06:23.951941 31033 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.548253ms
I0103 10:06:23.951980 31033 replica.cpp:320] Persisted replica status to VOTING
I0103 10:06:23.952121 31037 recover.cpp:578] Successfully joined the Paxos group
I0103 10:06:23.952390 31037 recover.cpp:462] Recover process terminated
I0103 10:06:23.952905 31037 log.cpp:659] Attempting to start the writer
I0103 10:06:23.954212 31038 replica.cpp:493] Replica received implicit promise request from (12862)@172.17.0.5:36256 with proposal 1
I0103 10:06:23.977155 31038 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.904527ms
I0103 10:06:23.977200 31038 replica.cpp:342] Persisted promised to 1
I0103 10:06:23.977845 31032 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0103 10:06:23.979231 31041 replica.cpp:388] Replica received explicit promise request from (12863)@172.17.0.5:36256 for position 0 with proposal 2
I0103 10:06:24.002146 31041 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.864524ms
I0103 10:06:24.002185 31041 replica.cpp:712] Persisted action at 0
I0103 10:06:24.003482 31036 replica.cpp:537] Replica received write request for position 0 from (12864)@172.17.0.5:36256
I0103 10:06:24.003551 31036 leveldb.cpp:436] Reading position from leveldb took 29417ns
I0103 10:06:24.027261 31036 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.663876ms
I0103 10:06:24.027299 31036 replica.cpp:712] Persisted action at 0
I0103 10:06:24.028159 31041 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0103 10:06:24.052376 31041 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.169573ms
I0103 10:06:24.052414 31041 replica.cpp:712] Persisted action at 0
I0103 10:06:24.052438 31041 replica.cpp:697] Replica learned NOP action at position 0
I0103 10:06:24.053149 31045 log.cpp:675] Writer started with ending position 0
I0103 10:06:24.054363 31041 leveldb.cpp:436] Reading position from leveldb took 34609ns
I0103 10:06:24.055371 31033 registrar.cpp:340] Successfully fetched the registry (0B) in 174.024192ms
I0103 10:06:24.055493 31033 registrar.cpp:439] Applied 1 operations in 28019ns; attempting to update the 'registry'
I0103 10:06:24.056323 31036 log.cpp:683] Attempting to append 170 bytes to the log
I0103 10:06:24.056495 31040 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0103 10:06:24.057356 31046 replica.cpp:537] Replica received write request for position 1 from (12865)@172.17.0.5:36256
I0103 10:06:24.077491 31046 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 20.087164ms
I0103 10:06:24.077532 31046 replica.cpp:712] Persisted action at 1
I0103 10:06:24.078441 31031 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0103 10:06:24.102677 31031 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.193814ms
I0103 10:06:24.102717 31031 replica.cpp:712] Persisted action at 1
I0103 10:06:24.102740 31031 replica.cpp:697] Replica learned APPEND action at position 1
I0103 10:06:24.104463 31045 registrar.cpp:484] Successfully updated the 'registry' in 48.908032ms
I0103 10:06:24.104679 31045 registrar.cpp:370] Successfully recovered registrar
I0103 10:06:24.104756 31035 log.cpp:702] Attempting to truncate the log to 1
I0103 10:06:24.104948 31033 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0103 10:06:24.105463 31040 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0103 10:06:24.105525 31044 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0103 10:06:24.105960 31036 replica.cpp:537] Replica received write request for position 2 from (12866)@172.17.0.5:36256
I0103 10:06:24.127794 31036 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 21.78832ms
I0103 10:06:24.127833 31036 replica.cpp:712] Persisted action at 2
I0103 10:06:24.128536 31040 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0103 10:06:24.152978 31040 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.39931ms
I0103 10:06:24.153059 31040 leveldb.cpp:399] Deleting ~1 keys from leveldb took 40203ns
I0103 10:06:24.153081 31040 replica.cpp:712] Persisted action at 2
I0103 10:06:24.153105 31040 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0103 10:06:24.156466 31012 scheduler.cpp:154] Version: 0.27.0
I0103 10:06:24.157127 31042 scheduler.cpp:236] New master detected at master@172.17.0.5:36256
I0103 10:06:24.158314 31035 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:36256
I0103 10:06:24.160380 31045 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 10:06:24.160948 31039 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:35767
I0103 10:06:24.161346 31039 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0103 10:06:24.161433 31039 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0103 10:06:24.161797 31039 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [  ]
I0103 10:06:24.162436 31034 master.hpp:1659] Sending heartbeat to ec5677a7-3657-4516-a9a2-2fb1676df5fd-0000
I0103 10:06:24.162822 31041 hierarchical.cpp:260] Added framework ec5677a7-3657-4516-a9a2-2fb1676df5fd-0000
I0103 10:06:24.162901 31041 hierarchical.cpp:1329] No resources available to allocate!
I0103 10:06:24.162955 31041 hierarchical.cpp:1423] No inverse offers to send out!
I0103 10:06:24.162992 31041 hierarchical.cpp:1079] Performed allocation for 0 slaves in 133182ns
I0103 10:06:24.163482 31035 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:36256
I0103 10:06:24.164039 31035 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:36256
I0103 10:06:24.164831 31045 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0103 10:06:24.164870 31035 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:36256
I0103 10:06:24.166674 31032 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 10:06:24.167199 31035 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:35768
I0103 10:06:24.167481 31035 master.cpp:2636] Processing REQUEST call for framework ec5677a7-3657-4516-a9a2-2fb1676df5fd-0000 (default)
I0103 10:06:24.167696 31036 hierarchical.cpp:579] Received resource request from framework ec5677a7-3657-4516-a9a2-2fb1676df5fd-0000
I0103 10:06:24.168066 31031 master.cpp:930] Master terminating
I0103 10:06:24.168301 31033 hierarchical.cpp:321] Removed framework ec5677a7-3657-4516-a9a2-2fb1676df5fd-0000
E0103 10:06:24.169953 31037 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[       OK ] ContentType/SchedulerTest.Request/1 (414 ms)
[----------] 22 tests from ContentType/SchedulerTest (15300 ms total)

[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (717932 ms total)
[  PASSED  ] 913 tests.
[  FAILED  ] 2 tests, listed below:
[  FAILED  ] ProvisionerDockerLocalStoreTest.LocalStoreTestWithTar
[  FAILED  ] ProvisionerDockerLocalStoreTest.MetadataManagerInitialization

 2 FAILED TESTS
  YOU HAVE 6 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-1451812778-17164
Untagged: mesos-1451812778-17164:latest
Deleted: 26c98aa3128fa1c60137fa9ead1df0ad52604d3a7774f6988346c14acdb80400
Deleted: 7861f0847ba3d6bb1ea8ac1788cd78749ad05672f9888f1faebbe18d96647464
Deleted: 253adc5bb6447f45fc72cf1f5843717ad4d6de7a579cc5f85e1b474d9ea12896
Deleted: 24ffe788f54679aed91dc08582f0ea854630d7f704a6b7cb7638d0a5cf3a56d4
Deleted: 49c49c88c0cb56dbe8728f6e7061a08d2bebbb27c63e08d50114e5c000a098ab
Deleted: 8b6bfbcd5486cf76c2fdfacc1a47802a0fb7a6564e1820415c153ebcd2d3034c
Deleted: 418a7788cf60bc4d0ed964b7459a0f60a82aae71c1bf2c9c9a1aa783ade6633a
Deleted: 39577ddc71b6ddfe2d9b4d9e8d2c0dffc1c745fa56e132472b6f50b50873e4a1
Deleted: 2551271882bcde909fa16b3ac96b3f19df80a7e93b50f3d9fa134351f37d1973
Deleted: ef029f566c79103b440f876587877e74af80f53eaceb0c01acc0e2d802f02d56
Deleted: 864aea00e64bc2ee598dfe89f1fa6f2d896c7e99580238cd29dba594130dc4cc
Deleted: 5cd88ab478b9baca0ae5f3aa7e937a2217f9d48ac5c9049e5e36a6cd923e73c7
Deleted: 9532f2c87ca16da73ddfb739dd80b2a9727422ba71fc20702d13c70347850d91

Error handling URL https://reviews.apache.org/api/review-requests/41731/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard f05eb74b905ebb1eec2db0b694e2ff0c34413d26

Build step 'Execute shell' marked build as failure

Build failed in Jenkins: mesos-reviewbot #10531

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10531/>

------------------------------------------
[...truncated 165035 lines...]
[       OK ] ContentType/SchedulerTest.Message/1 (663 ms)
[ RUN      ] ContentType/SchedulerTest.Request/0
I0103 08:56:51.594421 31016 leveldb.cpp:174] Opened db in 84.707564ms
I0103 08:56:51.619884 31016 leveldb.cpp:181] Compacted db in 25.419627ms
I0103 08:56:51.619949 31016 leveldb.cpp:196] Created db iterator in 20484ns
I0103 08:56:51.619969 31016 leveldb.cpp:202] Seeked to beginning of db in 2293ns
I0103 08:56:51.619982 31016 leveldb.cpp:271] Iterated through 0 keys in the db in 398ns
I0103 08:56:51.620020 31016 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0103 08:56:51.620539 31045 recover.cpp:447] Starting replica recovery
I0103 08:56:51.621093 31045 recover.cpp:473] Replica is in EMPTY status
I0103 08:56:51.622313 31046 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12832)@172.17.0.2:58080
I0103 08:56:51.622879 31049 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0103 08:56:51.623400 31042 recover.cpp:564] Updating replica status to STARTING
I0103 08:56:51.623739 31045 master.cpp:365] Master fb3f5bea-15c3-4782-9424-98aa13afe330 (4cd3539047c1) started on 172.17.0.2:58080
I0103 08:56:51.623764 31045 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/Nee8Yv/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/Nee8Yv/master" --zk_session_timeout="10secs"
I0103 08:56:51.624089 31045 master.cpp:414] Master allowing unauthenticated frameworks to register
I0103 08:56:51.624104 31045 master.cpp:417] Master only allowing authenticated slaves to register
I0103 08:56:51.624112 31045 credentials.hpp:35] Loading credentials for authentication from '/tmp/Nee8Yv/credentials'
I0103 08:56:51.624395 31045 master.cpp:456] Using default 'crammd5' authenticator
I0103 08:56:51.624539 31045 master.cpp:493] Authorization enabled
I0103 08:56:51.624733 31040 hierarchical.cpp:147] Initialized hierarchical allocator process
I0103 08:56:51.624773 31035 whitelist_watcher.cpp:77] No whitelist given
I0103 08:56:51.626643 31050 master.cpp:1629] The newly elected leader is master@172.17.0.2:58080 with id fb3f5bea-15c3-4782-9424-98aa13afe330
I0103 08:56:51.626688 31050 master.cpp:1642] Elected as the leading master!
I0103 08:56:51.626713 31050 master.cpp:1387] Recovering from registrar
I0103 08:56:51.626870 31047 registrar.cpp:307] Recovering registrar
I0103 08:56:51.657742 31044 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 34.164301ms
I0103 08:56:51.657779 31044 replica.cpp:320] Persisted replica status to STARTING
I0103 08:56:51.658043 31036 recover.cpp:473] Replica is in STARTING status
I0103 08:56:51.659354 31038 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12833)@172.17.0.2:58080
I0103 08:56:51.659610 31037 recover.cpp:193] Received a recover response from a replica in STARTING status
I0103 08:56:51.660221 31043 recover.cpp:564] Updating replica status to VOTING
I0103 08:56:51.682793 31036 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.396397ms
I0103 08:56:51.682831 31036 replica.cpp:320] Persisted replica status to VOTING
I0103 08:56:51.682965 31050 recover.cpp:578] Successfully joined the Paxos group
I0103 08:56:51.683235 31050 recover.cpp:462] Recover process terminated
I0103 08:56:51.683701 31047 log.cpp:659] Attempting to start the writer
I0103 08:56:51.685237 31036 replica.cpp:493] Replica received implicit promise request from (12834)@172.17.0.2:58080 with proposal 1
I0103 08:56:51.707942 31036 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.667061ms
I0103 08:56:51.707978 31036 replica.cpp:342] Persisted promised to 1
I0103 08:56:51.708703 31041 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0103 08:56:51.710186 31048 replica.cpp:388] Replica received explicit promise request from (12835)@172.17.0.2:58080 for position 0 with proposal 2
I0103 08:56:51.733052 31048 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.81864ms
I0103 08:56:51.733089 31048 replica.cpp:712] Persisted action at 0
I0103 08:56:51.734705 31049 replica.cpp:537] Replica received write request for position 0 from (12836)@172.17.0.2:58080
I0103 08:56:51.734788 31049 leveldb.cpp:436] Reading position from leveldb took 36911ns
I0103 08:56:51.758174 31049 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.32948ms
I0103 08:56:51.758213 31049 replica.cpp:712] Persisted action at 0
I0103 08:56:51.759019 31042 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0103 08:56:51.783273 31042 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.212938ms
I0103 08:56:51.783313 31042 replica.cpp:712] Persisted action at 0
I0103 08:56:51.783335 31042 replica.cpp:697] Replica learned NOP action at position 0
I0103 08:56:51.784083 31037 log.cpp:675] Writer started with ending position 0
I0103 08:56:51.785308 31050 leveldb.cpp:436] Reading position from leveldb took 33244ns
I0103 08:56:51.786332 31050 registrar.cpp:340] Successfully fetched the registry (0B) in 159.407104ms
I0103 08:56:51.786453 31050 registrar.cpp:439] Applied 1 operations in 26219ns; attempting to update the 'registry'
I0103 08:56:51.787293 31039 log.cpp:683] Attempting to append 170 bytes to the log
I0103 08:56:51.787421 31036 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0103 08:56:51.788343 31036 replica.cpp:537] Replica received write request for position 1 from (12837)@172.17.0.2:58080
I0103 08:56:51.808403 31036 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 20.009373ms
I0103 08:56:51.808441 31036 replica.cpp:712] Persisted action at 1
I0103 08:56:51.809187 31040 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0103 08:56:51.833513 31040 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.28082ms
I0103 08:56:51.833559 31040 replica.cpp:712] Persisted action at 1
I0103 08:56:51.833583 31040 replica.cpp:697] Replica learned APPEND action at position 1
I0103 08:56:51.834722 31042 registrar.cpp:484] Successfully updated the 'registry' in 48.200704ms
I0103 08:56:51.834878 31042 registrar.cpp:370] Successfully recovered registrar
I0103 08:56:51.834960 31049 log.cpp:702] Attempting to truncate the log to 1
I0103 08:56:51.835186 31045 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0103 08:56:51.835399 31040 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0103 08:56:51.835444 31042 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0103 08:56:51.836158 31048 replica.cpp:537] Replica received write request for position 2 from (12838)@172.17.0.2:58080
I0103 08:56:51.858692 31048 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 22.483431ms
I0103 08:56:51.858738 31048 replica.cpp:712] Persisted action at 2
I0103 08:56:51.859416 31037 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0103 08:56:51.883746 31037 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.233222ms
I0103 08:56:51.883851 31037 leveldb.cpp:399] Deleting ~1 keys from leveldb took 56065ns
I0103 08:56:51.883885 31037 replica.cpp:712] Persisted action at 2
I0103 08:56:51.883922 31037 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0103 08:56:51.886452 31016 scheduler.cpp:154] Version: 0.27.0
I0103 08:56:51.887179 31041 scheduler.cpp:236] New master detected at master@172.17.0.2:58080
I0103 08:56:51.888293 31035 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:58080
I0103 08:56:51.890274 31045 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 08:56:51.890888 31050 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:53213
I0103 08:56:51.891155 31050 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0103 08:56:51.891234 31050 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0103 08:56:51.891705 31050 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [  ]
I0103 08:56:51.892251 31046 master.hpp:1659] Sending heartbeat to fb3f5bea-15c3-4782-9424-98aa13afe330-0000
I0103 08:56:51.892277 31041 hierarchical.cpp:260] Added framework fb3f5bea-15c3-4782-9424-98aa13afe330-0000
I0103 08:56:51.892333 31041 hierarchical.cpp:1329] No resources available to allocate!
I0103 08:56:51.892360 31041 hierarchical.cpp:1423] No inverse offers to send out!
I0103 08:56:51.892381 31041 hierarchical.cpp:1079] Performed allocation for 0 slaves in 81038ns
I0103 08:56:51.893512 31048 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:58080
I0103 08:56:51.894034 31048 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:58080
I0103 08:56:51.894932 31044 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0103 08:56:51.895009 31048 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:58080
I0103 08:56:51.896836 31038 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 08:56:51.897402 31049 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:53214
I0103 08:56:51.897547 31049 master.cpp:2636] Processing REQUEST call for framework fb3f5bea-15c3-4782-9424-98aa13afe330-0000 (default)
I0103 08:56:51.897753 31047 hierarchical.cpp:579] Received resource request from framework fb3f5bea-15c3-4782-9424-98aa13afe330-0000
I0103 08:56:51.898051 31049 master.cpp:930] Master terminating
I0103 08:56:51.898285 31040 hierarchical.cpp:321] Removed framework fb3f5bea-15c3-4782-9424-98aa13afe330-0000
E0103 08:56:51.899785 31045 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[       OK ] ContentType/SchedulerTest.Request/0 (397 ms)
[ RUN      ] ContentType/SchedulerTest.Request/1
I0103 08:56:52.003738 31016 leveldb.cpp:174] Opened db in 97.217872ms
I0103 08:56:52.029258 31016 leveldb.cpp:181] Compacted db in 25.484327ms
I0103 08:56:52.029321 31016 leveldb.cpp:196] Created db iterator in 17969ns
I0103 08:56:52.029341 31016 leveldb.cpp:202] Seeked to beginning of db in 2067ns
I0103 08:56:52.029353 31016 leveldb.cpp:271] Iterated through 0 keys in the db in 208ns
I0103 08:56:52.029388 31016 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0103 08:56:52.030047 31036 recover.cpp:447] Starting replica recovery
I0103 08:56:52.030360 31036 recover.cpp:473] Replica is in EMPTY status
I0103 08:56:52.031530 31040 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12846)@172.17.0.2:58080
I0103 08:56:52.032995 31035 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0103 08:56:52.033486 31037 recover.cpp:564] Updating replica status to STARTING
I0103 08:56:52.034054 31038 master.cpp:365] Master 015e28d2-d07b-4b76-8066-2d220284240a (4cd3539047c1) started on 172.17.0.2:58080
I0103 08:56:52.034205 31038 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/HessGh/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/HessGh/master" --zk_session_timeout="10secs"
I0103 08:56:52.034540 31038 master.cpp:414] Master allowing unauthenticated frameworks to register
I0103 08:56:52.034556 31038 master.cpp:417] Master only allowing authenticated slaves to register
I0103 08:56:52.034572 31038 credentials.hpp:35] Loading credentials for authentication from '/tmp/HessGh/credentials'
I0103 08:56:52.034857 31038 master.cpp:456] Using default 'crammd5' authenticator
I0103 08:56:52.035004 31038 master.cpp:493] Authorization enabled
I0103 08:56:52.035212 31047 hierarchical.cpp:147] Initialized hierarchical allocator process
I0103 08:56:52.035217 31035 whitelist_watcher.cpp:77] No whitelist given
I0103 08:56:52.037068 31040 master.cpp:1629] The newly elected leader is master@172.17.0.2:58080 with id 015e28d2-d07b-4b76-8066-2d220284240a
I0103 08:56:52.037106 31040 master.cpp:1642] Elected as the leading master!
I0103 08:56:52.037147 31040 master.cpp:1387] Recovering from registrar
I0103 08:56:52.037300 31044 registrar.cpp:307] Recovering registrar
I0103 08:56:52.056298 31042 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.488439ms
I0103 08:56:52.056340 31042 replica.cpp:320] Persisted replica status to STARTING
I0103 08:56:52.056610 31046 recover.cpp:473] Replica is in STARTING status
I0103 08:56:52.057646 31043 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12847)@172.17.0.2:58080
I0103 08:56:52.057903 31042 recover.cpp:193] Received a recover response from a replica in STARTING status
I0103 08:56:52.058368 31040 recover.cpp:564] Updating replica status to VOTING
I0103 08:56:52.081424 31038 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.847041ms
I0103 08:56:52.081464 31038 replica.cpp:320] Persisted replica status to VOTING
I0103 08:56:52.081596 31039 recover.cpp:578] Successfully joined the Paxos group
I0103 08:56:52.081871 31039 recover.cpp:462] Recover process terminated
I0103 08:56:52.082315 31043 log.cpp:659] Attempting to start the writer
I0103 08:56:52.083477 31048 replica.cpp:493] Replica received implicit promise request from (12848)@172.17.0.2:58080 with proposal 1
I0103 08:56:52.106698 31048 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 23.186254ms
I0103 08:56:52.106741 31048 replica.cpp:342] Persisted promised to 1
I0103 08:56:52.107496 31036 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0103 08:56:52.108775 31037 replica.cpp:388] Replica received explicit promise request from (12849)@172.17.0.2:58080 for position 0 with proposal 2
I0103 08:56:52.131650 31037 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.830751ms
I0103 08:56:52.131685 31037 replica.cpp:712] Persisted action at 0
I0103 08:56:52.132820 31040 replica.cpp:537] Replica received write request for position 0 from (12850)@172.17.0.2:58080
I0103 08:56:52.132887 31040 leveldb.cpp:436] Reading position from leveldb took 27640ns
I0103 08:56:52.156769 31040 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.830809ms
I0103 08:56:52.156803 31040 replica.cpp:712] Persisted action at 0
I0103 08:56:52.157449 31039 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0103 08:56:52.181874 31039 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.389655ms
I0103 08:56:52.181913 31039 replica.cpp:712] Persisted action at 0
I0103 08:56:52.181936 31039 replica.cpp:697] Replica learned NOP action at position 0
I0103 08:56:52.182641 31040 log.cpp:675] Writer started with ending position 0
I0103 08:56:52.183789 31049 leveldb.cpp:436] Reading position from leveldb took 30846ns
I0103 08:56:52.184751 31047 registrar.cpp:340] Successfully fetched the registry (0B) in 147.30496ms
I0103 08:56:52.184864 31047 registrar.cpp:439] Applied 1 operations in 25549ns; attempting to update the 'registry'
I0103 08:56:52.185685 31040 log.cpp:683] Attempting to append 170 bytes to the log
I0103 08:56:52.185853 31047 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0103 08:56:52.186813 31042 replica.cpp:537] Replica received write request for position 1 from (12851)@172.17.0.2:58080
I0103 08:56:52.217573 31042 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 30.70995ms
I0103 08:56:52.217612 31042 replica.cpp:712] Persisted action at 1
I0103 08:56:52.218349 31050 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0103 08:56:52.251154 31050 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 32.737702ms
I0103 08:56:52.251196 31050 replica.cpp:712] Persisted action at 1
I0103 08:56:52.251219 31050 replica.cpp:697] Replica learned APPEND action at position 1
I0103 08:56:52.252380 31046 registrar.cpp:484] Successfully updated the 'registry' in 67.45216ms
I0103 08:56:52.252562 31046 registrar.cpp:370] Successfully recovered registrar
I0103 08:56:52.252727 31042 log.cpp:702] Attempting to truncate the log to 1
I0103 08:56:52.252933 31046 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0103 08:56:52.253288 31049 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0103 08:56:52.253310 31035 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0103 08:56:52.253937 31037 replica.cpp:537] Replica received write request for position 2 from (12852)@172.17.0.2:58080
I0103 08:56:52.292758 31037 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.773429ms
I0103 08:56:52.292795 31037 replica.cpp:712] Persisted action at 2
I0103 08:56:52.293666 31040 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0103 08:56:52.334614 31040 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 40.906273ms
I0103 08:56:52.334693 31040 leveldb.cpp:399] Deleting ~1 keys from leveldb took 40276ns
I0103 08:56:52.334719 31040 replica.cpp:712] Persisted action at 2
I0103 08:56:52.334743 31040 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0103 08:56:52.344507 31016 scheduler.cpp:154] Version: 0.27.0
I0103 08:56:52.345172 31042 scheduler.cpp:236] New master detected at master@172.17.0.2:58080
I0103 08:56:52.346247 31050 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:58080
I0103 08:56:52.348168 31049 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 08:56:52.348675 31035 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:53215
I0103 08:56:52.349081 31035 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0103 08:56:52.349191 31035 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0103 08:56:52.349506 31035 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [  ]
I0103 08:56:52.349938 31038 hierarchical.cpp:260] Added framework 015e28d2-d07b-4b76-8066-2d220284240a-0000
I0103 08:56:52.350014 31038 hierarchical.cpp:1329] No resources available to allocate!
I0103 08:56:52.350062 31038 hierarchical.cpp:1423] No inverse offers to send out!
I0103 08:56:52.350096 31038 hierarchical.cpp:1079] Performed allocation for 0 slaves in 124958ns
I0103 08:56:52.350149 31036 master.hpp:1659] Sending heartbeat to 015e28d2-d07b-4b76-8066-2d220284240a-0000
I0103 08:56:52.351055 31037 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:58080
I0103 08:56:52.351605 31037 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:58080
I0103 08:56:52.352316 31041 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0103 08:56:52.352396 31039 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:58080
I0103 08:56:52.354225 31042 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 08:56:52.354678 31036 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:53216
I0103 08:56:52.354923 31036 master.cpp:2636] Processing REQUEST call for framework 015e28d2-d07b-4b76-8066-2d220284240a-0000 (default)
I0103 08:56:52.355084 31040 hierarchical.cpp:579] Received resource request from framework 015e28d2-d07b-4b76-8066-2d220284240a-0000
I0103 08:56:52.355525 31039 master.cpp:930] Master terminating
I0103 08:56:52.355725 31036 hierarchical.cpp:321] Removed framework 015e28d2-d07b-4b76-8066-2d220284240a-0000
E0103 08:56:52.358103 31039 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[       OK ] ContentType/SchedulerTest.Request/1 (456 ms)
[----------] 22 tests from ContentType/SchedulerTest (15055 ms total)

[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (697402 ms total)
[  PASSED  ] 913 tests.
[  FAILED  ] 2 tests, listed below:
[  FAILED  ] ProvisionerDockerLocalStoreTest.LocalStoreTestWithTar
[  FAILED  ] ProvisionerDockerLocalStoreTest.MetadataManagerInitialization

 2 FAILED TESTS
  YOU HAVE 6 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-1451809177-4795
Untagged: mesos-1451809177-4795:latest
Deleted: 327660c48a1dc620a8214955fe25538ee7267d7b9f9f8f4618b82425f8a40b89
Deleted: 28e98d794dbe25f7698d19502b779278eb0aeb28db113bf44b64b74dda16660d
Deleted: dad750a9ff77ac134f382f0d1e847194c01d259dc392fbe9c1ce61b8f43bd296
Deleted: e1eb5c6dabacb735bec684f786cd79b1e29142ffe35cc9fec56be9527ba469f4
Deleted: 7d92fe783c7e1542f513283acb2cece3b503727414fff76d12810481534b3b30
Deleted: bc57ea5411e76e6993c68e70a852da7be471513f3a2deadbe1f0a9830b910587
Deleted: 671cd75d58cf3582b1ef391a07143656b1139b4ec58b89b2e193adc42dc7729c
Deleted: 034f5320afa9292120e1d506ec376a8178d4ad08d0ef7950ca0746f0c343bee1
Deleted: c1dc21088aec58589a5ac1e27f7e278403119af9914c933a3c99b02d2d1f3471
Deleted: 43e4ff7262e2ea4368ba19743a0f457feaf968d5c72b030e033b94e633b70a6f
Deleted: dfccdc8a129b7062dd3e167dc4efbd879e87125175cf9d1943d6c502fe53ffed
Deleted: 525de3b0fc5ba90ac444a785464a9419d09234e01db57d9a60c5a0eea0073652
Deleted: a9779b0df9c47ba3fb167a0e016e84ed3f11a9fd955b86e793efb7c3b865292f

Error handling URL https://reviews.apache.org/api/review-requests/41731/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard f05eb74b905ebb1eec2db0b694e2ff0c34413d26

Build step 'Execute shell' marked build as failure