You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2015/12/31 21:53:58 UTC
Build failed in Jenkins: mesos-reviewbot #10511
See <https://builds.apache.org/job/mesos-reviewbot/10511/changes>
Changes:
[yujie.jay] Added HDFS URI fetcher plugin.
[yujie.jay] Added tests for HDFS URI fetcher plugin.
------------------------------------------
[...truncated 165536 lines...]
[ RUN ] ContentType/SchedulerTest.Request/0
I1231 20:53:50.730231 31030 leveldb.cpp:174] Opened db in 111.276305ms
I1231 20:53:50.772346 31030 leveldb.cpp:181] Compacted db in 42.072055ms
I1231 20:53:50.772418 31030 leveldb.cpp:196] Created db iterator in 23864ns
I1231 20:53:50.772457 31030 leveldb.cpp:202] Seeked to beginning of db in 3037ns
I1231 20:53:50.772481 31030 leveldb.cpp:271] Iterated through 0 keys in the db in 683ns
I1231 20:53:50.772539 31030 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1231 20:53:50.773015 31062 recover.cpp:447] Starting replica recovery
I1231 20:53:50.773324 31062 recover.cpp:473] Replica is in EMPTY status
I1231 20:53:50.774607 31050 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12841)@172.17.0.2:33780
I1231 20:53:50.775054 31055 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1231 20:53:50.775702 31056 recover.cpp:564] Updating replica status to STARTING
I1231 20:53:50.776727 31055 master.cpp:365] Master cb8db66d-fc15-4119-b563-7f0e574102dd (0c1a98524b1f) started on 172.17.0.2:33780
I1231 20:53:50.776762 31055 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ta6YwP/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/ta6YwP/master" --zk_session_timeout="10secs"
I1231 20:53:50.777170 31055 master.cpp:414] Master allowing unauthenticated frameworks to register
I1231 20:53:50.777189 31055 master.cpp:417] Master only allowing authenticated slaves to register
I1231 20:53:50.777199 31055 credentials.hpp:35] Loading credentials for authentication from '/tmp/ta6YwP/credentials'
I1231 20:53:50.777456 31055 master.cpp:456] Using default 'crammd5' authenticator
I1231 20:53:50.777600 31055 master.cpp:493] Authorization enabled
I1231 20:53:50.777796 31056 hierarchical.cpp:147] Initialized hierarchical allocator process
I1231 20:53:50.777817 31061 whitelist_watcher.cpp:77] No whitelist given
I1231 20:53:50.779757 31051 master.cpp:1629] The newly elected leader is master@172.17.0.2:33780 with id cb8db66d-fc15-4119-b563-7f0e574102dd
I1231 20:53:50.779793 31051 master.cpp:1642] Elected as the leading master!
I1231 20:53:50.779809 31051 master.cpp:1387] Recovering from registrar
I1231 20:53:50.779947 31057 registrar.cpp:307] Recovering registrar
I1231 20:53:50.805418 31063 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 29.530205ms
I1231 20:53:50.805456 31063 replica.cpp:320] Persisted replica status to STARTING
I1231 20:53:50.805676 31056 recover.cpp:473] Replica is in STARTING status
I1231 20:53:50.806798 31058 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12842)@172.17.0.2:33780
I1231 20:53:50.806990 31051 recover.cpp:193] Received a recover response from a replica in STARTING status
I1231 20:53:50.807504 31054 recover.cpp:564] Updating replica status to VOTING
I1231 20:53:50.830503 31059 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.855018ms
I1231 20:53:50.830541 31059 replica.cpp:320] Persisted replica status to VOTING
I1231 20:53:50.830667 31056 recover.cpp:578] Successfully joined the Paxos group
I1231 20:53:50.830915 31056 recover.cpp:462] Recover process terminated
I1231 20:53:50.831393 31062 log.cpp:659] Attempting to start the writer
I1231 20:53:50.832468 31050 replica.cpp:493] Replica received implicit promise request from (12843)@172.17.0.2:33780 with proposal 1
I1231 20:53:50.855587 31050 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 23.086871ms
I1231 20:53:50.855613 31050 replica.cpp:342] Persisted promised to 1
I1231 20:53:50.856156 31057 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1231 20:53:50.857159 31055 replica.cpp:388] Replica received explicit promise request from (12844)@172.17.0.2:33780 for position 0 with proposal 2
I1231 20:53:50.885787 31055 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 28.593156ms
I1231 20:53:50.885815 31055 replica.cpp:712] Persisted action at 0
I1231 20:53:50.886718 31058 replica.cpp:537] Replica received write request for position 0 from (12845)@172.17.0.2:33780
I1231 20:53:50.886778 31058 leveldb.cpp:436] Reading position from leveldb took 30338ns
2015-12-31 20:53:50,892:31030(0x2b984ca68700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:50080] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I1231 20:53:50.927683 31058 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.859855ms
I1231 20:53:50.927727 31058 replica.cpp:712] Persisted action at 0
I1231 20:53:50.928655 31054 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I1231 20:53:50.969326 31054 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.581603ms
I1231 20:53:50.969365 31054 replica.cpp:712] Persisted action at 0
I1231 20:53:50.969388 31054 replica.cpp:697] Replica learned NOP action at position 0
I1231 20:53:50.970032 31058 log.cpp:675] Writer started with ending position 0
I1231 20:53:50.971261 31057 leveldb.cpp:436] Reading position from leveldb took 29644ns
I1231 20:53:50.972337 31056 registrar.cpp:340] Successfully fetched the registry (0B) in 192.324864ms
I1231 20:53:50.972462 31056 registrar.cpp:439] Applied 1 operations in 29649ns; attempting to update the 'registry'
I1231 20:53:50.973315 31051 log.cpp:683] Attempting to append 170 bytes to the log
I1231 20:53:50.973459 31050 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1231 20:53:50.974294 31064 replica.cpp:537] Replica received write request for position 1 from (12846)@172.17.0.2:33780
I1231 20:53:51.011157 31064 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 36.810795ms
I1231 20:53:51.011196 31064 replica.cpp:712] Persisted action at 1
I1231 20:53:51.011948 31057 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I1231 20:53:51.053011 31057 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 41.022567ms
I1231 20:53:51.053057 31057 replica.cpp:712] Persisted action at 1
I1231 20:53:51.053082 31057 replica.cpp:697] Replica learned APPEND action at position 1
I1231 20:53:51.054225 31051 registrar.cpp:484] Successfully updated the 'registry' in 81.698048ms
I1231 20:53:51.054374 31051 registrar.cpp:370] Successfully recovered registrar
I1231 20:53:51.054529 31049 log.cpp:702] Attempting to truncate the log to 1
I1231 20:53:51.054767 31056 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1231 20:53:51.055151 31064 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I1231 20:53:51.055177 31050 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I1231 20:53:51.055914 31061 replica.cpp:537] Replica received write request for position 2 from (12847)@172.17.0.2:33780
I1231 20:53:51.094699 31061 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.741593ms
I1231 20:53:51.094738 31061 replica.cpp:712] Persisted action at 2
I1231 20:53:51.095623 31052 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I1231 20:53:51.136472 31052 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 40.806895ms
I1231 20:53:51.136554 31052 leveldb.cpp:399] Deleting ~1 keys from leveldb took 42036ns
I1231 20:53:51.136587 31052 replica.cpp:712] Persisted action at 2
I1231 20:53:51.136610 31052 replica.cpp:697] Replica learned TRUNCATE action at position 2
I1231 20:53:51.146242 31030 scheduler.cpp:154] Version: 0.27.0
I1231 20:53:51.146857 31055 scheduler.cpp:236] New master detected at master@172.17.0.2:33780
I1231 20:53:51.148046 31063 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:33780
I1231 20:53:51.149788 31058 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1231 20:53:51.150275 31063 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:45387
I1231 20:53:51.150452 31063 master.cpp:1891] Received subscription request for HTTP framework 'default'
I1231 20:53:51.150508 31063 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1231 20:53:51.150779 31063 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1231 20:53:51.151165 31054 hierarchical.cpp:260] Added framework cb8db66d-fc15-4119-b563-7f0e574102dd-0000
I1231 20:53:51.151217 31052 master.hpp:1659] Sending heartbeat to cb8db66d-fc15-4119-b563-7f0e574102dd-0000
I1231 20:53:51.151278 31054 hierarchical.cpp:1329] No resources available to allocate!
I1231 20:53:51.151316 31054 hierarchical.cpp:1423] No inverse offers to send out!
I1231 20:53:51.151345 31054 hierarchical.cpp:1079] Performed allocation for 0 slaves in 150766ns
I1231 20:53:51.151979 31061 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:33780
I1231 20:53:51.152433 31061 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:33780
I1231 20:53:51.153065 31063 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I1231 20:53:51.153147 31061 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:33780
I1231 20:53:51.154609 31063 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1231 20:53:51.155071 31051 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:45388
I1231 20:53:51.155203 31051 master.cpp:2636] Processing REQUEST call for framework cb8db66d-fc15-4119-b563-7f0e574102dd-0000 (default)
I1231 20:53:51.155356 31053 hierarchical.cpp:579] Received resource request from framework cb8db66d-fc15-4119-b563-7f0e574102dd-0000
I1231 20:53:51.155951 31056 master.cpp:930] Master terminating
I1231 20:53:51.156162 31059 hierarchical.cpp:321] Removed framework cb8db66d-fc15-4119-b563-7f0e574102dd-0000
E1231 20:53:51.156785 31050 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (544 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I1231 20:53:51.289566 31030 leveldb.cpp:174] Opened db in 126.927714ms
I1231 20:53:51.323262 31030 leveldb.cpp:181] Compacted db in 33.654422ms
I1231 20:53:51.323325 31030 leveldb.cpp:196] Created db iterator in 17905ns
I1231 20:53:51.323345 31030 leveldb.cpp:202] Seeked to beginning of db in 2075ns
I1231 20:53:51.323357 31030 leveldb.cpp:271] Iterated through 0 keys in the db in 442ns
I1231 20:53:51.323393 31030 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1231 20:53:51.323915 31055 recover.cpp:447] Starting replica recovery
I1231 20:53:51.324373 31052 recover.cpp:473] Replica is in EMPTY status
I1231 20:53:51.325439 31054 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12855)@172.17.0.2:33780
I1231 20:53:51.326050 31059 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1231 20:53:51.326575 31053 recover.cpp:564] Updating replica status to STARTING
I1231 20:53:51.326949 31049 master.cpp:365] Master 96b5e32d-2992-413c-8da6-dbe03776717b (0c1a98524b1f) started on 172.17.0.2:33780
I1231 20:53:51.326980 31049 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/XRIE2Y/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/XRIE2Y/master" --zk_session_timeout="10secs"
I1231 20:53:51.327422 31049 master.cpp:414] Master allowing unauthenticated frameworks to register
I1231 20:53:51.327445 31049 master.cpp:417] Master only allowing authenticated slaves to register
I1231 20:53:51.327462 31049 credentials.hpp:35] Loading credentials for authentication from '/tmp/XRIE2Y/credentials'
I1231 20:53:51.327749 31049 master.cpp:456] Using default 'crammd5' authenticator
I1231 20:53:51.327896 31049 master.cpp:493] Authorization enabled
I1231 20:53:51.328070 31058 hierarchical.cpp:147] Initialized hierarchical allocator process
I1231 20:53:51.328100 31055 whitelist_watcher.cpp:77] No whitelist given
I1231 20:53:51.329879 31050 master.cpp:1629] The newly elected leader is master@172.17.0.2:33780 with id 96b5e32d-2992-413c-8da6-dbe03776717b
I1231 20:53:51.329913 31050 master.cpp:1642] Elected as the leading master!
I1231 20:53:51.329938 31050 master.cpp:1387] Recovering from registrar
I1231 20:53:51.330096 31056 registrar.cpp:307] Recovering registrar
I1231 20:53:51.348193 31060 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 21.330942ms
I1231 20:53:51.348232 31060 replica.cpp:320] Persisted replica status to STARTING
I1231 20:53:51.348487 31062 recover.cpp:473] Replica is in STARTING status
I1231 20:53:51.349673 31058 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12856)@172.17.0.2:33780
I1231 20:53:51.349997 31056 recover.cpp:193] Received a recover response from a replica in STARTING status
I1231 20:53:51.350441 31051 recover.cpp:564] Updating replica status to VOTING
I1231 20:53:51.373195 31049 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.626473ms
I1231 20:53:51.373224 31049 replica.cpp:320] Persisted replica status to VOTING
I1231 20:53:51.373324 31060 recover.cpp:578] Successfully joined the Paxos group
I1231 20:53:51.373528 31060 recover.cpp:462] Recover process terminated
I1231 20:53:51.373929 31055 log.cpp:659] Attempting to start the writer
I1231 20:53:51.374943 31061 replica.cpp:493] Replica received implicit promise request from (12857)@172.17.0.2:33780 with proposal 1
I1231 20:53:51.423308 31061 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 48.336371ms
I1231 20:53:51.423339 31061 replica.cpp:342] Persisted promised to 1
I1231 20:53:51.424111 31050 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1231 20:53:51.425153 31056 replica.cpp:388] Replica received explicit promise request from (12858)@172.17.0.2:33780 for position 0 with proposal 2
I1231 20:53:51.448449 31056 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 23.240802ms
I1231 20:53:51.448488 31056 replica.cpp:712] Persisted action at 0
I1231 20:53:51.449692 31052 replica.cpp:537] Replica received write request for position 0 from (12859)@172.17.0.2:33780
I1231 20:53:51.449759 31052 leveldb.cpp:436] Reading position from leveldb took 30499ns
I1231 20:53:51.473562 31052 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.756556ms
I1231 20:53:51.473600 31052 replica.cpp:712] Persisted action at 0
I1231 20:53:51.474314 31059 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I1231 20:53:51.498672 31059 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.317106ms
I1231 20:53:51.498711 31059 replica.cpp:712] Persisted action at 0
I1231 20:53:51.498733 31059 replica.cpp:697] Replica learned NOP action at position 0
I1231 20:53:51.499475 31055 log.cpp:675] Writer started with ending position 0
I1231 20:53:51.500757 31061 leveldb.cpp:436] Reading position from leveldb took 32340ns
I1231 20:53:51.501793 31052 registrar.cpp:340] Successfully fetched the registry (0B) in 171.597824ms
I1231 20:53:51.501926 31052 registrar.cpp:439] Applied 1 operations in 26904ns; attempting to update the 'registry'
I1231 20:53:51.502707 31059 log.cpp:683] Attempting to append 170 bytes to the log
I1231 20:53:51.502903 31064 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1231 20:53:51.503806 31064 replica.cpp:537] Replica received write request for position 1 from (12860)@172.17.0.2:33780
I1231 20:53:51.523792 31064 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 19.94227ms
I1231 20:53:51.523831 31064 replica.cpp:712] Persisted action at 1
I1231 20:53:51.524690 31053 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I1231 20:53:51.548967 31053 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.187621ms
I1231 20:53:51.549006 31053 replica.cpp:712] Persisted action at 1
I1231 20:53:51.549027 31053 replica.cpp:697] Replica learned APPEND action at position 1
I1231 20:53:51.550983 31064 registrar.cpp:484] Successfully updated the 'registry' in 48.98176ms
I1231 20:53:51.551177 31064 registrar.cpp:370] Successfully recovered registrar
I1231 20:53:51.551218 31054 log.cpp:702] Attempting to truncate the log to 1
I1231 20:53:51.551398 31052 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1231 20:53:51.551766 31061 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I1231 20:53:51.551800 31060 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I1231 20:53:51.552462 31063 replica.cpp:537] Replica received write request for position 2 from (12861)@172.17.0.2:33780
I1231 20:53:51.574023 31063 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 21.513011ms
I1231 20:53:51.574061 31063 replica.cpp:712] Persisted action at 2
I1231 20:53:51.574931 31053 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I1231 20:53:51.599145 31053 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.155266ms
I1231 20:53:51.599236 31053 leveldb.cpp:399] Deleting ~1 keys from leveldb took 49969ns
I1231 20:53:51.599264 31053 replica.cpp:712] Persisted action at 2
I1231 20:53:51.599298 31053 replica.cpp:697] Replica learned TRUNCATE action at position 2
I1231 20:53:51.602691 31030 scheduler.cpp:154] Version: 0.27.0
I1231 20:53:51.603348 31053 scheduler.cpp:236] New master detected at master@172.17.0.2:33780
I1231 20:53:51.604449 31056 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:33780
I1231 20:53:51.606650 31059 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1231 20:53:51.607184 31052 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:45389
I1231 20:53:51.607563 31052 master.cpp:1891] Received subscription request for HTTP framework 'default'
I1231 20:53:51.607630 31052 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1231 20:53:51.607951 31052 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1231 20:53:51.608438 31056 hierarchical.cpp:260] Added framework 96b5e32d-2992-413c-8da6-dbe03776717b-0000
I1231 20:53:51.608577 31059 master.hpp:1659] Sending heartbeat to 96b5e32d-2992-413c-8da6-dbe03776717b-0000
I1231 20:53:51.608625 31056 hierarchical.cpp:1329] No resources available to allocate!
I1231 20:53:51.608667 31056 hierarchical.cpp:1423] No inverse offers to send out!
I1231 20:53:51.608700 31056 hierarchical.cpp:1079] Performed allocation for 0 slaves in 121119ns
I1231 20:53:51.609457 31061 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:33780
I1231 20:53:51.609968 31061 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:33780
I1231 20:53:51.610687 31056 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I1231 20:53:51.610769 31061 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:33780
I1231 20:53:51.612648 31059 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1231 20:53:51.613206 31052 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:45390
I1231 20:53:51.613459 31052 master.cpp:2636] Processing REQUEST call for framework 96b5e32d-2992-413c-8da6-dbe03776717b-0000 (default)
I1231 20:53:51.613633 31061 hierarchical.cpp:579] Received resource request from framework 96b5e32d-2992-413c-8da6-dbe03776717b-0000
I1231 20:53:51.613919 31064 master.cpp:930] Master terminating
I1231 20:53:51.614274 31061 hierarchical.cpp:321] Removed framework 96b5e32d-2992-413c-8da6-dbe03776717b-0000
E1231 20:53:51.615764 31061 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (459 ms)
[----------] 22 tests from ContentType/SchedulerTest (15939 ms total)
[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (731279 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 1make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1451592593-11124
Untagged: mesos-1451592593-11124:latest
Deleted: c54177d77bb55051d07d76b87b09cf8d11a65e35637861bdb6f56d530cf60b51
Deleted: 4c63aac2e91b42ef511c84131725054650b4fb627df1d32c635623c43b08c4ee
Deleted: da3ae01af4bf376bc379a579d97e0722a72ff94b7884c9f229483f9ca9db882b
Deleted: 7665565ef4e0b44ad7aa8766944a22fc0fca191416364a4015e1bfd14cd5cc2b
Deleted: 220dc9042758036c2fcfa55dc9ccca37d9d27eb0f53a6d31bac3870bda987a4b
Deleted: f72bbc8812d355cb4736abcac8e266cc550b8f60abcdc45ee18b73354af9fc7c
Deleted: 0e42a5a0a4e57e1c9640343a8fce30ea22a2374ba07edac87d52b06b1c35840b
Deleted: 3e6d66c1bc83031075356c3d011e87170c51f984aa5835847215baf0a46314d2
Deleted: 78d2f3cbd4b05e03c882df0199ea43daf2a51a05b3b643952b7283f0291eebb9
Deleted: 9a9aed12a9b5ce8b01d0b0d63aec8a8aa5331561f3e5661df75369a5109b2bda
Deleted: c86d8ce179b677850194e0a7334d35f173838c8e663a003fa6babf25689b8f2e
Deleted: 6cd4c73f4d8bbeb3f114975e26b5eea92bc10685214abbd2d8bcca55263f3b85
Deleted: 53fde8b3351020fe55567291f9a39b28236c5dd889b07f2b353f3c435c15d419
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 #10519
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10519/>
Build failed in Jenkins: mesos-reviewbot #10518
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10518/>
------------------------------------------
[...truncated 166151 lines...]
[ OK ] ContentType/SchedulerTest.Message/1 (881 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0101 22:35:55.883417 31019 leveldb.cpp:174] Opened db in 115.416274ms
I0101 22:35:55.935228 31019 leveldb.cpp:181] Compacted db in 51.724141ms
I0101 22:35:55.935336 31019 leveldb.cpp:196] Created db iterator in 32884ns
I0101 22:35:55.935360 31019 leveldb.cpp:202] Seeked to beginning of db in 4983ns
I0101 22:35:55.935374 31019 leveldb.cpp:271] Iterated through 0 keys in the db in 388ns
I0101 22:35:55.935438 31019 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0101 22:35:55.936384 31038 recover.cpp:447] Starting replica recovery
I0101 22:35:55.937042 31038 recover.cpp:473] Replica is in EMPTY status
I0101 22:35:55.938730 31051 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12823)@172.17.0.2:58932
I0101 22:35:55.939395 31047 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0101 22:35:55.939839 31043 recover.cpp:564] Updating replica status to STARTING
I0101 22:35:55.941004 31050 master.cpp:365] Master bed7a913-a882-4381-9abf-c56a6b056858 (6a95f11e1db6) started on 172.17.0.2:58932
I0101 22:35:55.941030 31050 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/nrvJA6/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/nrvJA6/master" --zk_session_timeout="10secs"
I0101 22:35:55.941411 31050 master.cpp:414] Master allowing unauthenticated frameworks to register
I0101 22:35:55.941431 31050 master.cpp:417] Master only allowing authenticated slaves to register
I0101 22:35:55.941442 31050 credentials.hpp:35] Loading credentials for authentication from '/tmp/nrvJA6/credentials'
I0101 22:35:55.941792 31050 master.cpp:456] Using default 'crammd5' authenticator
I0101 22:35:55.941954 31050 master.cpp:493] Authorization enabled
I0101 22:35:55.942225 31042 hierarchical.cpp:147] Initialized hierarchical allocator process
I0101 22:35:55.942226 31039 whitelist_watcher.cpp:77] No whitelist given
I0101 22:35:55.944427 31051 master.cpp:1629] The newly elected leader is master@172.17.0.2:58932 with id bed7a913-a882-4381-9abf-c56a6b056858
I0101 22:35:55.944469 31051 master.cpp:1642] Elected as the leading master!
I0101 22:35:55.944497 31051 master.cpp:1387] Recovering from registrar
I0101 22:35:55.944689 31041 registrar.cpp:307] Recovering registrar
I0101 22:35:55.968621 31045 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 28.557074ms
I0101 22:35:55.968684 31045 replica.cpp:320] Persisted replica status to STARTING
I0101 22:35:55.969008 31046 recover.cpp:473] Replica is in STARTING status
I0101 22:35:55.970238 31045 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12824)@172.17.0.2:58932
I0101 22:35:55.970711 31053 recover.cpp:193] Received a recover response from a replica in STARTING status
I0101 22:35:55.971258 31038 recover.cpp:564] Updating replica status to VOTING
I0101 22:35:56.002233 31039 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.775481ms
I0101 22:35:56.002329 31039 replica.cpp:320] Persisted replica status to VOTING
I0101 22:35:56.002607 31046 recover.cpp:578] Successfully joined the Paxos group
I0101 22:35:56.002846 31046 recover.cpp:462] Recover process terminated
I0101 22:35:56.003543 31050 log.cpp:659] Attempting to start the writer
I0101 22:35:56.004704 31043 replica.cpp:493] Replica received implicit promise request from (12825)@172.17.0.2:58932 with proposal 1
I0101 22:35:56.063122 31043 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 58.359209ms
I0101 22:35:56.063216 31043 replica.cpp:342] Persisted promised to 1
I0101 22:35:56.063961 31048 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0101 22:35:56.065145 31044 replica.cpp:388] Replica received explicit promise request from (12826)@172.17.0.2:58932 for position 0 with proposal 2
I0101 22:35:56.113477 31044 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 48.263627ms
I0101 22:35:56.113579 31044 replica.cpp:712] Persisted action at 0
I0101 22:35:56.115460 31043 replica.cpp:537] Replica received write request for position 0 from (12827)@172.17.0.2:58932
I0101 22:35:56.115583 31043 leveldb.cpp:436] Reading position from leveldb took 63744ns
I0101 22:35:56.180411 31043 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 64.728864ms
I0101 22:35:56.180510 31043 replica.cpp:712] Persisted action at 0
I0101 22:35:56.181655 31039 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0101 22:35:56.230556 31039 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 48.826139ms
I0101 22:35:56.230646 31039 replica.cpp:712] Persisted action at 0
I0101 22:35:56.230687 31039 replica.cpp:697] Replica learned NOP action at position 0
I0101 22:35:56.231925 31039 log.cpp:675] Writer started with ending position 0
I0101 22:35:56.233243 31049 leveldb.cpp:436] Reading position from leveldb took 56470ns
I0101 22:35:56.234326 31042 registrar.cpp:340] Successfully fetched the registry (0B) in 289.587968ms
I0101 22:35:56.234462 31042 registrar.cpp:439] Applied 1 operations in 32421ns; attempting to update the 'registry'
I0101 22:35:56.235426 31044 log.cpp:683] Attempting to append 170 bytes to the log
I0101 22:35:56.235599 31042 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0101 22:35:56.236485 31044 replica.cpp:537] Replica received write request for position 1 from (12828)@172.17.0.2:58932
I0101 22:35:56.289353 31044 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 52.805971ms
I0101 22:35:56.289428 31044 replica.cpp:712] Persisted action at 1
I0101 22:35:56.290143 31041 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0101 22:35:56.339320 31041 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 49.118611ms
I0101 22:35:56.339421 31041 replica.cpp:712] Persisted action at 1
I0101 22:35:56.339468 31041 replica.cpp:697] Replica learned APPEND action at position 1
I0101 22:35:56.341094 31045 registrar.cpp:484] Successfully updated the 'registry' in 106.55488ms
I0101 22:35:56.341300 31045 registrar.cpp:370] Successfully recovered registrar
I0101 22:35:56.341593 31053 log.cpp:702] Attempting to truncate the log to 1
I0101 22:35:56.341868 31051 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0101 22:35:56.342020 31038 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0101 22:35:56.342070 31053 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0101 22:35:56.342998 31046 replica.cpp:537] Replica received write request for position 2 from (12829)@172.17.0.2:58932
I0101 22:35:56.385823 31046 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 42.76184ms
I0101 22:35:56.385895 31046 replica.cpp:712] Persisted action at 2
I0101 22:35:56.386739 31051 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0101 22:35:56.436097 31051 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 49.308395ms
I0101 22:35:56.436230 31051 leveldb.cpp:399] Deleting ~1 keys from leveldb took 56587ns
I0101 22:35:56.436256 31051 replica.cpp:712] Persisted action at 2
I0101 22:35:56.436286 31051 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0101 22:35:56.444037 31019 scheduler.cpp:154] Version: 0.27.0
I0101 22:35:56.444907 31039 scheduler.cpp:236] New master detected at master@172.17.0.2:58932
I0101 22:35:56.446053 31047 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:58932
I0101 22:35:56.448092 31040 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 22:35:56.448554 31039 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:53139
I0101 22:35:56.448742 31039 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0101 22:35:56.448814 31039 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0101 22:35:56.449162 31042 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0101 22:35:56.449657 31050 hierarchical.cpp:260] Added framework bed7a913-a882-4381-9abf-c56a6b056858-0000
I0101 22:35:56.449714 31045 master.hpp:1659] Sending heartbeat to bed7a913-a882-4381-9abf-c56a6b056858-0000
I0101 22:35:56.449723 31050 hierarchical.cpp:1329] No resources available to allocate!
I0101 22:35:56.449769 31050 hierarchical.cpp:1423] No inverse offers to send out!
I0101 22:35:56.449791 31050 hierarchical.cpp:1079] Performed allocation for 0 slaves in 110007ns
I0101 22:35:56.450518 31040 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:58932
I0101 22:35:56.451025 31040 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:58932
I0101 22:35:56.452409 31040 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:58932
I0101 22:35:56.453336 31050 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0101 22:35:56.453934 31050 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 22:35:56.454401 31050 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:53140
I0101 22:35:56.454524 31050 master.cpp:2636] Processing REQUEST call for framework bed7a913-a882-4381-9abf-c56a6b056858-0000 (default)
I0101 22:35:56.454661 31038 hierarchical.cpp:579] Received resource request from framework bed7a913-a882-4381-9abf-c56a6b056858-0000
I0101 22:35:56.455031 31045 master.cpp:930] Master terminating
I0101 22:35:56.455297 31052 hierarchical.cpp:321] Removed framework bed7a913-a882-4381-9abf-c56a6b056858-0000
E0101 22:35:56.456648 31038 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (695 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0101 22:35:56.604296 31019 leveldb.cpp:174] Opened db in 141.864789ms
I0101 22:35:56.656949 31019 leveldb.cpp:181] Compacted db in 52.563089ms
I0101 22:35:56.657066 31019 leveldb.cpp:196] Created db iterator in 33578ns
I0101 22:35:56.657089 31019 leveldb.cpp:202] Seeked to beginning of db in 3836ns
I0101 22:35:56.657102 31019 leveldb.cpp:271] Iterated through 0 keys in the db in 435ns
I0101 22:35:56.657181 31019 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0101 22:35:56.658115 31049 recover.cpp:447] Starting replica recovery
I0101 22:35:56.658421 31041 recover.cpp:473] Replica is in EMPTY status
I0101 22:35:56.659484 31039 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12837)@172.17.0.2:58932
I0101 22:35:56.659915 31043 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0101 22:35:56.660398 31039 recover.cpp:564] Updating replica status to STARTING
I0101 22:35:56.662847 31040 master.cpp:365] Master fd370785-e345-482c-a2b6-7b8f98cea3a3 (6a95f11e1db6) started on 172.17.0.2:58932
I0101 22:35:56.662881 31040 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/miEq8R/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/miEq8R/master" --zk_session_timeout="10secs"
I0101 22:35:56.663292 31040 master.cpp:414] Master allowing unauthenticated frameworks to register
I0101 22:35:56.663312 31040 master.cpp:417] Master only allowing authenticated slaves to register
I0101 22:35:56.663326 31040 credentials.hpp:35] Loading credentials for authentication from '/tmp/miEq8R/credentials'
I0101 22:35:56.663647 31040 master.cpp:456] Using default 'crammd5' authenticator
I0101 22:35:56.663801 31040 master.cpp:493] Authorization enabled
I0101 22:35:56.663983 31051 hierarchical.cpp:147] Initialized hierarchical allocator process
I0101 22:35:56.663995 31046 whitelist_watcher.cpp:77] No whitelist given
I0101 22:35:56.666262 31051 master.cpp:1629] The newly elected leader is master@172.17.0.2:58932 with id fd370785-e345-482c-a2b6-7b8f98cea3a3
I0101 22:35:56.666304 31051 master.cpp:1642] Elected as the leading master!
I0101 22:35:56.666327 31051 master.cpp:1387] Recovering from registrar
I0101 22:35:56.666450 31052 registrar.cpp:307] Recovering registrar
I0101 22:35:56.694926 31043 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 34.357019ms
I0101 22:35:56.695053 31043 replica.cpp:320] Persisted replica status to STARTING
I0101 22:35:56.695426 31041 recover.cpp:473] Replica is in STARTING status
I0101 22:35:56.696910 31043 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12838)@172.17.0.2:58932
I0101 22:35:56.697173 31041 recover.cpp:193] Received a recover response from a replica in STARTING status
I0101 22:35:56.697700 31047 recover.cpp:564] Updating replica status to VOTING
I0101 22:35:56.740629 31040 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 42.744497ms
I0101 22:35:56.740700 31040 replica.cpp:320] Persisted replica status to VOTING
I0101 22:35:56.740890 31047 recover.cpp:578] Successfully joined the Paxos group
I0101 22:35:56.741317 31047 recover.cpp:462] Recover process terminated
I0101 22:35:56.741662 31048 log.cpp:659] Attempting to start the writer
I0101 22:35:56.743017 31053 replica.cpp:493] Replica received implicit promise request from (12839)@172.17.0.2:58932 with proposal 1
I0101 22:35:56.765807 31053 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.735541ms
I0101 22:35:56.765882 31053 replica.cpp:342] Persisted promised to 1
I0101 22:35:56.766628 31053 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0101 22:35:56.768061 31049 replica.cpp:388] Replica received explicit promise request from (12840)@172.17.0.2:58932 for position 0 with proposal 2
I0101 22:35:56.791013 31049 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.883146ms
I0101 22:35:56.791087 31049 replica.cpp:712] Persisted action at 0
I0101 22:35:56.792517 31041 replica.cpp:537] Replica received write request for position 0 from (12841)@172.17.0.2:58932
I0101 22:35:56.792598 31041 leveldb.cpp:436] Reading position from leveldb took 41660ns
I0101 22:35:56.816159 31041 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.49032ms
I0101 22:35:56.816236 31041 replica.cpp:712] Persisted action at 0
I0101 22:35:56.816983 31041 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0101 22:35:56.841629 31041 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.59475ms
I0101 22:35:56.841702 31041 replica.cpp:712] Persisted action at 0
I0101 22:35:56.841728 31041 replica.cpp:697] Replica learned NOP action at position 0
I0101 22:35:56.842705 31041 log.cpp:675] Writer started with ending position 0
I0101 22:35:56.843848 31049 leveldb.cpp:436] Reading position from leveldb took 48294ns
I0101 22:35:56.844786 31043 registrar.cpp:340] Successfully fetched the registry (0B) in 178.292992ms
I0101 22:35:56.844900 31043 registrar.cpp:439] Applied 1 operations in 31400ns; attempting to update the 'registry'
I0101 22:35:56.845612 31046 log.cpp:683] Attempting to append 170 bytes to the log
I0101 22:35:56.845751 31051 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0101 22:35:56.846536 31050 replica.cpp:537] Replica received write request for position 1 from (12842)@172.17.0.2:58932
I0101 22:35:56.887979 31050 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 41.383266ms
I0101 22:35:56.888051 31050 replica.cpp:712] Persisted action at 1
I0101 22:35:56.888842 31038 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0101 22:35:56.947387 31038 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 58.492679ms
I0101 22:35:56.947473 31038 replica.cpp:712] Persisted action at 1
I0101 22:35:56.947509 31038 replica.cpp:697] Replica learned APPEND action at position 1
I0101 22:35:56.949388 31046 registrar.cpp:484] Successfully updated the 'registry' in 104.423168ms
I0101 22:35:56.949555 31046 registrar.cpp:370] Successfully recovered registrar
I0101 22:35:56.949704 31038 log.cpp:702] Attempting to truncate the log to 1
I0101 22:35:56.949859 31049 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0101 22:35:56.950029 31038 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0101 22:35:56.950009 31051 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0101 22:35:56.951239 31046 replica.cpp:537] Replica received write request for position 2 from (12843)@172.17.0.2:58932
I0101 22:35:56.989645 31046 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.333403ms
I0101 22:35:56.989716 31046 replica.cpp:712] Persisted action at 2
I0101 22:35:56.990767 31039 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0101 22:35:57.031610 31039 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 40.791688ms
I0101 22:35:57.031740 31039 leveldb.cpp:399] Deleting ~1 keys from leveldb took 59032ns
I0101 22:35:57.031762 31039 replica.cpp:712] Persisted action at 2
I0101 22:35:57.031790 31039 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0101 22:35:57.042912 31019 scheduler.cpp:154] Version: 0.27.0
I0101 22:35:57.044065 31050 scheduler.cpp:236] New master detected at master@172.17.0.2:58932
I0101 22:35:57.045231 31038 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:58932
I0101 22:35:57.048015 31047 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 22:35:57.048822 31047 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:53148
I0101 22:35:57.049440 31047 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0101 22:35:57.049535 31047 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0101 22:35:57.050011 31053 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0101 22:35:57.050602 31047 hierarchical.cpp:260] Added framework fd370785-e345-482c-a2b6-7b8f98cea3a3-0000
I0101 22:35:57.050706 31047 hierarchical.cpp:1329] No resources available to allocate!
I0101 22:35:57.050758 31047 hierarchical.cpp:1423] No inverse offers to send out!
I0101 22:35:57.050791 31047 hierarchical.cpp:1079] Performed allocation for 0 slaves in 155136ns
I0101 22:35:57.050916 31049 master.hpp:1659] Sending heartbeat to fd370785-e345-482c-a2b6-7b8f98cea3a3-0000
I0101 22:35:57.051873 31052 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:58932
I0101 22:35:57.052371 31052 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:58932
I0101 22:35:57.053078 31038 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0101 22:35:57.053133 31048 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:58932
I0101 22:35:57.054946 31053 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 22:35:57.055467 31053 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:53149
I0101 22:35:57.055806 31053 master.cpp:2636] Processing REQUEST call for framework fd370785-e345-482c-a2b6-7b8f98cea3a3-0000 (default)
I0101 22:35:57.055995 31044 hierarchical.cpp:579] Received resource request from framework fd370785-e345-482c-a2b6-7b8f98cea3a3-0000
I0101 22:35:57.056303 31019 master.cpp:930] Master terminating
I0101 22:35:57.056509 31044 hierarchical.cpp:321] Removed framework fd370785-e345-482c-a2b6-7b8f98cea3a3-0000
E0101 22:35:57.057874 31045 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (601 ms)
[----------] 22 tests from ContentType/SchedulerTest (19435 ms total)
[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (853709 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-1451685015-28723
Untagged: mesos-1451685015-28723:latest
Deleted: fdf745ae05af46c81f72c3b5859b749e89e1222c9ec244b18dad8c84c7ccea48
Deleted: aee4784408e13d48925a8c427a4abc28ef5fb60878060c6e15bbb8c226d7d37d
Deleted: 323cb42e5630af48bbdbb8a11fd5572a23716e6354a9e189807df0e187e8963c
Deleted: 46d3e4746d1d0dbaa8abb9af7eeb0c2adffa9fc048d026998e732d5d5548a0ea
Deleted: 294bdb56360c11846469d5bad39be556a0db95a97400a51b859a3ee882e51095
Deleted: c96565a5c0fa41a45263500dfa31ba1607168d752a9a6f3f2c6ae42ac4a1b3f2
Deleted: 6021d680a96ff8049d093318f67588c8af1a9b879ad54945f9435145d90ada56
Deleted: 3b6494a2cf65209b6082ca010a7d7b3d2fd2b084930eaff12453cc43901a9470
Deleted: 49771110dfd00da52154feb99fd325428f33082255d7ac236e1e96fcb3abd475
Deleted: 50b3dc05ca38032d85db72fdd7194b967357e3481717c82a67e42387c4ff8f44
Deleted: a5f09ff9d138e60d6855277c7098c4407f600917d9f42552b1d22d0e801b86a9
Deleted: 13512da729ad7a856860b675618364e68d4b2659f6f80393e2f6bc3ae883807d
Deleted: 0f5078695b860d984a2fa79fbf05c6f3dbfe771cdc7bb0f2614d7de45dd831bb
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 #10517
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10517/>
------------------------------------------
[...truncated 165742 lines...]
[ OK ] ContentType/SchedulerTest.Message/1 (944 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0101 05:27:56.807873 31018 leveldb.cpp:174] Opened db in 132.962268ms
I0101 05:27:56.852802 31018 leveldb.cpp:181] Compacted db in 44.88852ms
I0101 05:27:56.852865 31018 leveldb.cpp:196] Created db iterator in 18910ns
I0101 05:27:56.852886 31018 leveldb.cpp:202] Seeked to beginning of db in 1920ns
I0101 05:27:56.852897 31018 leveldb.cpp:271] Iterated through 0 keys in the db in 305ns
I0101 05:27:56.852936 31018 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0101 05:27:56.853621 31051 recover.cpp:447] Starting replica recovery
I0101 05:27:56.854074 31051 recover.cpp:473] Replica is in EMPTY status
I0101 05:27:56.855047 31037 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12834)@172.17.0.2:56458
I0101 05:27:56.855479 31051 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0101 05:27:56.856559 31045 master.cpp:365] Master 7100f71a-86cb-42bc-ad2c-6d9db44a3686 (da49798f2d01) started on 172.17.0.2:56458
I0101 05:27:56.856582 31045 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/oEVqkG/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/oEVqkG/master" --zk_session_timeout="10secs"
I0101 05:27:56.856899 31041 recover.cpp:564] Updating replica status to STARTING
I0101 05:27:56.856962 31045 master.cpp:414] Master allowing unauthenticated frameworks to register
I0101 05:27:56.856986 31045 master.cpp:417] Master only allowing authenticated slaves to register
I0101 05:27:56.857000 31045 credentials.hpp:35] Loading credentials for authentication from '/tmp/oEVqkG/credentials'
I0101 05:27:56.857321 31045 master.cpp:456] Using default 'crammd5' authenticator
I0101 05:27:56.857476 31045 master.cpp:493] Authorization enabled
I0101 05:27:56.857658 31041 hierarchical.cpp:147] Initialized hierarchical allocator process
I0101 05:27:56.857779 31039 whitelist_watcher.cpp:77] No whitelist given
I0101 05:27:56.859465 31050 master.cpp:1629] The newly elected leader is master@172.17.0.2:56458 with id 7100f71a-86cb-42bc-ad2c-6d9db44a3686
I0101 05:27:56.859495 31050 master.cpp:1642] Elected as the leading master!
I0101 05:27:56.859519 31050 master.cpp:1387] Recovering from registrar
I0101 05:27:56.859681 31041 registrar.cpp:307] Recovering registrar
I0101 05:27:56.894410 31042 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 37.3455ms
I0101 05:27:56.894446 31042 replica.cpp:320] Persisted replica status to STARTING
I0101 05:27:56.894666 31037 recover.cpp:473] Replica is in STARTING status
I0101 05:27:56.895745 31049 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12835)@172.17.0.2:56458
I0101 05:27:56.896044 31039 recover.cpp:193] Received a recover response from a replica in STARTING status
I0101 05:27:56.896466 31044 recover.cpp:564] Updating replica status to VOTING
I0101 05:27:56.936203 31052 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.601453ms
I0101 05:27:56.936239 31052 replica.cpp:320] Persisted replica status to VOTING
I0101 05:27:56.936345 31050 recover.cpp:578] Successfully joined the Paxos group
I0101 05:27:56.936595 31050 recover.cpp:462] Recover process terminated
I0101 05:27:56.937041 31046 log.cpp:659] Attempting to start the writer
I0101 05:27:56.938339 31046 replica.cpp:493] Replica received implicit promise request from (12836)@172.17.0.2:56458 with proposal 1
I0101 05:27:56.977987 31046 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.604774ms
I0101 05:27:56.978023 31046 replica.cpp:342] Persisted promised to 1
I0101 05:27:56.978904 31042 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0101 05:27:56.980264 31043 replica.cpp:388] Replica received explicit promise request from (12837)@172.17.0.2:56458 for position 0 with proposal 2
I0101 05:27:57.019816 31043 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 39.50552ms
I0101 05:27:57.019860 31043 replica.cpp:712] Persisted action at 0
I0101 05:27:57.021057 31044 replica.cpp:537] Replica received write request for position 0 from (12838)@172.17.0.2:56458
I0101 05:27:57.021162 31044 leveldb.cpp:436] Reading position from leveldb took 57293ns
I0101 05:27:57.061615 31044 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.399861ms
I0101 05:27:57.061653 31044 replica.cpp:712] Persisted action at 0
I0101 05:27:57.062374 31043 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0101 05:27:57.103353 31043 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.941585ms
I0101 05:27:57.103390 31043 replica.cpp:712] Persisted action at 0
I0101 05:27:57.103412 31043 replica.cpp:697] Replica learned NOP action at position 0
I0101 05:27:57.104233 31048 log.cpp:675] Writer started with ending position 0
I0101 05:27:57.105357 31048 leveldb.cpp:436] Reading position from leveldb took 35714ns
I0101 05:27:57.106400 31048 registrar.cpp:340] Successfully fetched the registry (0B) in 246.617088ms
I0101 05:27:57.106534 31048 registrar.cpp:439] Applied 1 operations in 27347ns; attempting to update the 'registry'
I0101 05:27:57.107353 31038 log.cpp:683] Attempting to append 170 bytes to the log
I0101 05:27:57.107488 31050 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0101 05:27:57.108343 31041 replica.cpp:537] Replica received write request for position 1 from (12839)@172.17.0.2:56458
I0101 05:27:57.145222 31041 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 36.832287ms
I0101 05:27:57.145262 31041 replica.cpp:712] Persisted action at 1
I0101 05:27:57.146040 31045 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0101 05:27:57.190196 31045 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 44.114066ms
I0101 05:27:57.190233 31045 replica.cpp:712] Persisted action at 1
I0101 05:27:57.190256 31045 replica.cpp:697] Replica learned APPEND action at position 1
I0101 05:27:57.191296 31051 registrar.cpp:484] Successfully updated the 'registry' in 84.696064ms
I0101 05:27:57.191488 31051 registrar.cpp:370] Successfully recovered registrar
I0101 05:27:57.191576 31052 log.cpp:702] Attempting to truncate the log to 1
I0101 05:27:57.191700 31046 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0101 05:27:57.191990 31042 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0101 05:27:57.192034 31038 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0101 05:27:57.192539 31043 replica.cpp:537] Replica received write request for position 2 from (12840)@172.17.0.2:56458
I0101 05:27:57.225360 31043 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 32.787118ms
I0101 05:27:57.225399 31043 replica.cpp:712] Persisted action at 2
I0101 05:27:57.226279 31051 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0101 05:27:57.242871 31051 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 16.54797ms
I0101 05:27:57.242954 31051 leveldb.cpp:399] Deleting ~1 keys from leveldb took 42031ns
I0101 05:27:57.242976 31051 replica.cpp:712] Persisted action at 2
I0101 05:27:57.243000 31051 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0101 05:27:57.253185 31018 scheduler.cpp:154] Version: 0.27.0
I0101 05:27:57.253820 31037 scheduler.cpp:236] New master detected at master@172.17.0.2:56458
I0101 05:27:57.255059 31040 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:56458
I0101 05:27:57.257164 31052 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 05:27:57.257841 31038 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:55746
I0101 05:27:57.258090 31038 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0101 05:27:57.258179 31038 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0101 05:27:57.258512 31038 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0101 05:27:57.258890 31042 hierarchical.cpp:260] Added framework 7100f71a-86cb-42bc-ad2c-6d9db44a3686-0000
I0101 05:27:57.258963 31042 hierarchical.cpp:1329] No resources available to allocate!
I0101 05:27:57.258990 31045 master.hpp:1659] Sending heartbeat to 7100f71a-86cb-42bc-ad2c-6d9db44a3686-0000
I0101 05:27:57.258996 31042 hierarchical.cpp:1423] No inverse offers to send out!
I0101 05:27:57.259054 31042 hierarchical.cpp:1079] Performed allocation for 0 slaves in 128872ns
I0101 05:27:57.260006 31047 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:56458
I0101 05:27:57.260738 31047 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:56458
I0101 05:27:57.261554 31052 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0101 05:27:57.261638 31047 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:56458
I0101 05:27:57.263478 31039 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 05:27:57.263938 31050 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:55747
I0101 05:27:57.264070 31050 master.cpp:2636] Processing REQUEST call for framework 7100f71a-86cb-42bc-ad2c-6d9db44a3686-0000 (default)
I0101 05:27:57.264317 31040 hierarchical.cpp:579] Received resource request from framework 7100f71a-86cb-42bc-ad2c-6d9db44a3686-0000
I0101 05:27:57.264714 31050 master.cpp:930] Master terminating
I0101 05:27:57.265013 31045 hierarchical.cpp:321] Removed framework 7100f71a-86cb-42bc-ad2c-6d9db44a3686-0000
E0101 05:27:57.266216 31044 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (598 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0101 05:27:57.394415 31018 leveldb.cpp:174] Opened db in 121.58621ms
I0101 05:27:57.436422 31018 leveldb.cpp:181] Compacted db in 41.965037ms
I0101 05:27:57.436483 31018 leveldb.cpp:196] Created db iterator in 16627ns
I0101 05:27:57.436503 31018 leveldb.cpp:202] Seeked to beginning of db in 1902ns
I0101 05:27:57.436514 31018 leveldb.cpp:271] Iterated through 0 keys in the db in 310ns
I0101 05:27:57.436549 31018 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0101 05:27:57.437034 31037 recover.cpp:447] Starting replica recovery
I0101 05:27:57.437356 31037 recover.cpp:473] Replica is in EMPTY status
I0101 05:27:57.438020 31050 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12848)@172.17.0.2:56458
I0101 05:27:57.438415 31048 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0101 05:27:57.438784 31038 recover.cpp:564] Updating replica status to STARTING
I0101 05:27:57.439339 31051 master.cpp:365] Master 7bada703-dfbb-47aa-a489-696750706fc7 (da49798f2d01) started on 172.17.0.2:56458
I0101 05:27:57.439357 31051 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/2rfnTd/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/2rfnTd/master" --zk_session_timeout="10secs"
I0101 05:27:57.439585 31051 master.cpp:414] Master allowing unauthenticated frameworks to register
I0101 05:27:57.439595 31051 master.cpp:417] Master only allowing authenticated slaves to register
I0101 05:27:57.439601 31051 credentials.hpp:35] Loading credentials for authentication from '/tmp/2rfnTd/credentials'
I0101 05:27:57.439803 31051 master.cpp:456] Using default 'crammd5' authenticator
I0101 05:27:57.439904 31051 master.cpp:493] Authorization enabled
I0101 05:27:57.440047 31042 hierarchical.cpp:147] Initialized hierarchical allocator process
I0101 05:27:57.440055 31044 whitelist_watcher.cpp:77] No whitelist given
I0101 05:27:57.441545 31052 master.cpp:1629] The newly elected leader is master@172.17.0.2:56458 with id 7bada703-dfbb-47aa-a489-696750706fc7
I0101 05:27:57.441578 31052 master.cpp:1642] Elected as the leading master!
I0101 05:27:57.441596 31052 master.cpp:1387] Recovering from registrar
I0101 05:27:57.441741 31041 registrar.cpp:307] Recovering registrar
I0101 05:27:57.470532 31050 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.605742ms
I0101 05:27:57.470567 31050 replica.cpp:320] Persisted replica status to STARTING
I0101 05:27:57.470752 31051 recover.cpp:473] Replica is in STARTING status
I0101 05:27:57.471701 31045 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12849)@172.17.0.2:56458
I0101 05:27:57.472049 31040 recover.cpp:193] Received a recover response from a replica in STARTING status
I0101 05:27:57.472427 31042 recover.cpp:564] Updating replica status to VOTING
I0101 05:27:57.512233 31048 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.682105ms
I0101 05:27:57.512270 31048 replica.cpp:320] Persisted replica status to VOTING
I0101 05:27:57.512382 31045 recover.cpp:578] Successfully joined the Paxos group
I0101 05:27:57.512696 31045 recover.cpp:462] Recover process terminated
I0101 05:27:57.513247 31052 log.cpp:659] Attempting to start the writer
I0101 05:27:57.514508 31040 replica.cpp:493] Replica received implicit promise request from (12850)@172.17.0.2:56458 with proposal 1
I0101 05:27:57.553968 31040 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.429373ms
I0101 05:27:57.553995 31040 replica.cpp:342] Persisted promised to 1
I0101 05:27:57.554723 31046 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0101 05:27:57.556166 31038 replica.cpp:388] Replica received explicit promise request from (12851)@172.17.0.2:56458 for position 0 with proposal 2
I0101 05:27:57.595976 31038 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 39.762928ms
I0101 05:27:57.596021 31038 replica.cpp:712] Persisted action at 0
I0101 05:27:57.597301 31042 replica.cpp:537] Replica received write request for position 0 from (12852)@172.17.0.2:56458
I0101 05:27:57.597357 31042 leveldb.cpp:436] Reading position from leveldb took 26834ns
I0101 05:27:57.637670 31042 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.267372ms
I0101 05:27:57.637709 31042 replica.cpp:712] Persisted action at 0
I0101 05:27:57.638517 31046 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0101 05:27:57.679425 31046 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.806271ms
I0101 05:27:57.679453 31046 replica.cpp:712] Persisted action at 0
I0101 05:27:57.679469 31046 replica.cpp:697] Replica learned NOP action at position 0
I0101 05:27:57.680217 31044 log.cpp:675] Writer started with ending position 0
I0101 05:27:57.681390 31045 leveldb.cpp:436] Reading position from leveldb took 31704ns
I0101 05:27:57.682343 31051 registrar.cpp:340] Successfully fetched the registry (0B) in 240.553984ms
I0101 05:27:57.682461 31051 registrar.cpp:439] Applied 1 operations in 24544ns; attempting to update the 'registry'
I0101 05:27:57.683287 31042 log.cpp:683] Attempting to append 170 bytes to the log
I0101 05:27:57.683444 31037 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0101 05:27:57.684324 31047 replica.cpp:537] Replica received write request for position 1 from (12853)@172.17.0.2:56458
I0101 05:27:57.729506 31047 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 45.133648ms
I0101 05:27:57.729545 31047 replica.cpp:712] Persisted action at 1
I0101 05:27:57.730378 31047 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0101 05:27:57.771358 31047 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 40.941653ms
I0101 05:27:57.771396 31047 replica.cpp:712] Persisted action at 1
I0101 05:27:57.771420 31047 replica.cpp:697] Replica learned APPEND action at position 1
I0101 05:27:57.772564 31052 registrar.cpp:484] Successfully updated the 'registry' in 90.034944ms
I0101 05:27:57.772723 31052 registrar.cpp:370] Successfully recovered registrar
I0101 05:27:57.772888 31043 log.cpp:702] Attempting to truncate the log to 1
I0101 05:27:57.773046 31039 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0101 05:27:57.773207 31038 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0101 05:27:57.773298 31044 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0101 05:27:57.774106 31043 replica.cpp:537] Replica received write request for position 2 from (12854)@172.17.0.2:56458
I0101 05:27:57.813122 31043 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.956165ms
I0101 05:27:57.813184 31043 replica.cpp:712] Persisted action at 2
I0101 05:27:57.813886 31051 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0101 05:27:57.854943 31051 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 41.015656ms
I0101 05:27:57.855028 31051 leveldb.cpp:399] Deleting ~1 keys from leveldb took 44149ns
I0101 05:27:57.855062 31051 replica.cpp:712] Persisted action at 2
I0101 05:27:57.855085 31051 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0101 05:27:57.864615 31018 scheduler.cpp:154] Version: 0.27.0
I0101 05:27:57.865263 31040 scheduler.cpp:236] New master detected at master@172.17.0.2:56458
I0101 05:27:57.866523 31050 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:56458
I0101 05:27:57.868557 31038 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 05:27:57.869058 31049 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:55748
I0101 05:27:57.869472 31049 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0101 05:27:57.869537 31049 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0101 05:27:57.869843 31049 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0101 05:27:57.870317 31039 hierarchical.cpp:260] Added framework 7bada703-dfbb-47aa-a489-696750706fc7-0000
I0101 05:27:57.870383 31039 hierarchical.cpp:1329] No resources available to allocate!
I0101 05:27:57.870450 31048 master.hpp:1659] Sending heartbeat to 7bada703-dfbb-47aa-a489-696750706fc7-0000
I0101 05:27:57.870517 31039 hierarchical.cpp:1423] No inverse offers to send out!
I0101 05:27:57.870554 31039 hierarchical.cpp:1079] Performed allocation for 0 slaves in 205274ns
I0101 05:27:57.871409 31038 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:56458
I0101 05:27:57.871919 31038 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:56458
I0101 05:27:57.872951 31040 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0101 05:27:57.872990 31038 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:56458
I0101 05:27:57.874894 31045 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 05:27:57.875394 31038 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:55749
I0101 05:27:57.875644 31038 master.cpp:2636] Processing REQUEST call for framework 7bada703-dfbb-47aa-a489-696750706fc7-0000 (default)
I0101 05:27:57.875818 31043 hierarchical.cpp:579] Received resource request from framework 7bada703-dfbb-47aa-a489-696750706fc7-0000
I0101 05:27:57.876258 31038 master.cpp:930] Master terminating
I0101 05:27:57.876472 31051 hierarchical.cpp:321] Removed framework 7bada703-dfbb-47aa-a489-696750706fc7-0000
E0101 05:27:57.877720 31047 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (611 ms)
[----------] 22 tests from ContentType/SchedulerTest (16101 ms total)
[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (728428 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-1451623776-8726
Untagged: mesos-1451623776-8726:latest
Deleted: 4a3ebe931dba15aea58ac47c3b9f92a1b23374f5a49b8cc05cc9d8737c83fa9c
Deleted: 0fed94f059e337e27665355051c364b9bb3e383906a568ff1362d18aef17ed56
Deleted: c998ff325c11fa5fb522a07faf9729e63cf1984b937a1d8c1420cbb3fd10e411
Deleted: 5b9f08a322266e4738d0b83eeda7fc39734c88e8a2d7890f9261c485869263d9
Deleted: 33e0d7ff42a1c94eb21b7fe4087c0fc2b6604ab052efa65abb1580280b6dd5f1
Deleted: 0416527c76ce10f09e76dc41951eaaa75c946777107e50ba205de4a36ad5437e
Deleted: 619cf825dd41b4712b9baa657809d4af90f3fc852dffec838c6e4c445e246bf9
Deleted: b3be9e40a649d35a7ec4d2e802a47fae14c9119056c181e9bef33fe929bf8fc3
Deleted: d810e54d37a2f2ab57a3548e7837ccffdd0025be89652e5d925c00c3ac321a68
Deleted: 5ccbbf6d0bb84f9d762c66e43901cad4f4941e50e59f3426d41697606de58d9f
Deleted: 4815704f30606776a5626280c84d9be20277ab32c95dd33a37a5eea262359952
Deleted: 46f90c83637d73d9a0ee77ae63df98638cd68001540dc3028ab0fe78b120e751
Deleted: c26c1c89c5790fa6044dc67cfa58b6f2e2654aea31dc1d80a3fa8c54c180d8c6
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 #10516
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10516/>
------------------------------------------
[...truncated 165366 lines...]
[ OK ] ContentType/SchedulerTest.Message/1 (762 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0101 02:51:30.003588 31016 leveldb.cpp:174] Opened db in 83.468544ms
I0101 02:51:30.045824 31016 leveldb.cpp:181] Compacted db in 42.165663ms
I0101 02:51:30.045889 31016 leveldb.cpp:196] Created db iterator in 20037ns
I0101 02:51:30.045910 31016 leveldb.cpp:202] Seeked to beginning of db in 2122ns
I0101 02:51:30.045922 31016 leveldb.cpp:271] Iterated through 0 keys in the db in 458ns
I0101 02:51:30.045960 31016 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0101 02:51:30.046497 31046 recover.cpp:447] Starting replica recovery
I0101 02:51:30.046952 31046 recover.cpp:473] Replica is in EMPTY status
I0101 02:51:30.048137 31049 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12821)@172.17.0.5:35106
I0101 02:51:30.048648 31050 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0101 02:51:30.049172 31046 recover.cpp:564] Updating replica status to STARTING
I0101 02:51:30.050076 31044 master.cpp:365] Master d1be98d8-4a96-43ab-8f74-51a5bd6ce205 (9e617c76a5a5) started on 172.17.0.5:35106
I0101 02:51:30.050106 31044 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/McIY5t/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/McIY5t/master" --zk_session_timeout="10secs"
I0101 02:51:30.050438 31044 master.cpp:414] Master allowing unauthenticated frameworks to register
I0101 02:51:30.050452 31044 master.cpp:417] Master only allowing authenticated slaves to register
I0101 02:51:30.050462 31044 credentials.hpp:35] Loading credentials for authentication from '/tmp/McIY5t/credentials'
I0101 02:51:30.050760 31044 master.cpp:456] Using default 'crammd5' authenticator
I0101 02:51:30.050907 31044 master.cpp:493] Authorization enabled
I0101 02:51:30.051091 31046 whitelist_watcher.cpp:77] No whitelist given
I0101 02:51:30.051096 31042 hierarchical.cpp:147] Initialized hierarchical allocator process
I0101 02:51:30.053025 31040 master.cpp:1629] The newly elected leader is master@172.17.0.5:35106 with id d1be98d8-4a96-43ab-8f74-51a5bd6ce205
I0101 02:51:30.053066 31040 master.cpp:1642] Elected as the leading master!
I0101 02:51:30.053086 31040 master.cpp:1387] Recovering from registrar
I0101 02:51:30.053259 31041 registrar.cpp:307] Recovering registrar
I0101 02:51:30.070567 31043 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 21.220676ms
I0101 02:51:30.070631 31043 replica.cpp:320] Persisted replica status to STARTING
I0101 02:51:30.070902 31045 recover.cpp:473] Replica is in STARTING status
I0101 02:51:30.071868 31036 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12822)@172.17.0.5:35106
I0101 02:51:30.072084 31047 recover.cpp:193] Received a recover response from a replica in STARTING status
I0101 02:51:30.072541 31039 recover.cpp:564] Updating replica status to VOTING
I0101 02:51:30.095731 31038 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.995708ms
I0101 02:51:30.095767 31038 replica.cpp:320] Persisted replica status to VOTING
I0101 02:51:30.095903 31048 recover.cpp:578] Successfully joined the Paxos group
I0101 02:51:30.096154 31048 recover.cpp:462] Recover process terminated
I0101 02:51:30.096648 31044 log.cpp:659] Attempting to start the writer
I0101 02:51:30.097745 31041 replica.cpp:493] Replica received implicit promise request from (12823)@172.17.0.5:35106 with proposal 1
I0101 02:51:30.120789 31041 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 23.011088ms
I0101 02:51:30.120826 31041 replica.cpp:342] Persisted promised to 1
I0101 02:51:30.121532 31049 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0101 02:51:30.122666 31041 replica.cpp:388] Replica received explicit promise request from (12824)@172.17.0.5:35106 for position 0 with proposal 2
I0101 02:51:30.145894 31041 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 23.173371ms
I0101 02:51:30.145932 31041 replica.cpp:712] Persisted action at 0
I0101 02:51:30.147279 31041 replica.cpp:537] Replica received write request for position 0 from (12825)@172.17.0.5:35106
I0101 02:51:30.147362 31041 leveldb.cpp:436] Reading position from leveldb took 41049ns
I0101 02:51:30.171136 31041 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.707712ms
I0101 02:51:30.171183 31041 replica.cpp:712] Persisted action at 0
I0101 02:51:30.172147 31044 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0101 02:51:30.196249 31044 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.057861ms
I0101 02:51:30.196295 31044 replica.cpp:712] Persisted action at 0
I0101 02:51:30.196321 31044 replica.cpp:697] Replica learned NOP action at position 0
I0101 02:51:30.197032 31049 log.cpp:675] Writer started with ending position 0
I0101 02:51:30.198230 31050 leveldb.cpp:436] Reading position from leveldb took 37462ns
I0101 02:51:30.199360 31038 registrar.cpp:340] Successfully fetched the registry (0B) in 145.944832ms
I0101 02:51:30.199481 31038 registrar.cpp:439] Applied 1 operations in 27514ns; attempting to update the 'registry'
I0101 02:51:30.200316 31041 log.cpp:683] Attempting to append 170 bytes to the log
I0101 02:51:30.200459 31047 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0101 02:51:30.201249 31046 replica.cpp:537] Replica received write request for position 1 from (12826)@172.17.0.5:35106
I0101 02:51:30.221236 31046 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 19.936651ms
I0101 02:51:30.221276 31046 replica.cpp:712] Persisted action at 1
I0101 02:51:30.222009 31041 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0101 02:51:30.246405 31041 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.296363ms
I0101 02:51:30.246445 31041 replica.cpp:712] Persisted action at 1
I0101 02:51:30.246467 31041 replica.cpp:697] Replica learned APPEND action at position 1
I0101 02:51:30.247598 31049 registrar.cpp:484] Successfully updated the 'registry' in 48.048128ms
I0101 02:51:30.247871 31049 registrar.cpp:370] Successfully recovered registrar
I0101 02:51:30.248080 31037 log.cpp:702] Attempting to truncate the log to 1
I0101 02:51:30.248242 31050 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0101 02:51:30.248335 31040 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0101 02:51:30.248392 31043 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0101 02:51:30.249028 31037 replica.cpp:537] Replica received write request for position 2 from (12827)@172.17.0.5:35106
I0101 02:51:30.271453 31037 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 22.390678ms
I0101 02:51:30.271482 31037 replica.cpp:712] Persisted action at 2
I0101 02:51:30.272166 31049 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0101 02:51:30.296561 31049 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.357269ms
I0101 02:51:30.296663 31049 leveldb.cpp:399] Deleting ~1 keys from leveldb took 60424ns
I0101 02:51:30.296691 31049 replica.cpp:712] Persisted action at 2
I0101 02:51:30.296716 31049 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0101 02:51:30.299289 31016 scheduler.cpp:154] Version: 0.27.0
I0101 02:51:30.299993 31044 scheduler.cpp:236] New master detected at master@172.17.0.5:35106
I0101 02:51:30.301180 31039 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:35106
I0101 02:51:30.303236 31038 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 02:51:30.303778 31035 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:35295
I0101 02:51:30.303978 31035 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0101 02:51:30.304044 31035 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0101 02:51:30.304348 31035 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0101 02:51:30.304746 31045 hierarchical.cpp:260] Added framework d1be98d8-4a96-43ab-8f74-51a5bd6ce205-0000
I0101 02:51:30.304808 31046 master.hpp:1659] Sending heartbeat to d1be98d8-4a96-43ab-8f74-51a5bd6ce205-0000
I0101 02:51:30.304816 31045 hierarchical.cpp:1329] No resources available to allocate!
I0101 02:51:30.304908 31045 hierarchical.cpp:1423] No inverse offers to send out!
I0101 02:51:30.304945 31045 hierarchical.cpp:1079] Performed allocation for 0 slaves in 169656ns
I0101 02:51:30.305770 31037 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:35106
I0101 02:51:30.306277 31037 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:35106
I0101 02:51:30.306975 31045 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0101 02:51:30.307207 31046 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:35106
I0101 02:51:30.308794 31037 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 02:51:30.309344 31040 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:35296
I0101 02:51:30.309454 31040 master.cpp:2636] Processing REQUEST call for framework d1be98d8-4a96-43ab-8f74-51a5bd6ce205-0000 (default)
I0101 02:51:30.309634 31036 hierarchical.cpp:579] Received resource request from framework d1be98d8-4a96-43ab-8f74-51a5bd6ce205-0000
I0101 02:51:30.309927 31035 master.cpp:930] Master terminating
I0101 02:51:30.310127 31045 hierarchical.cpp:321] Removed framework d1be98d8-4a96-43ab-8f74-51a5bd6ce205-0000
E0101 02:51:30.311393 31043 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
I0101 02:51:30.425891 31016 leveldb.cpp:174] Opened db in 108.612561ms
I0101 02:51:30.465581 31016 leveldb.cpp:181] Compacted db in 39.645243ms
I0101 02:51:30.465675 31016 leveldb.cpp:196] Created db iterator in 19630ns
I0101 02:51:30.465695 31016 leveldb.cpp:202] Seeked to beginning of db in 1760ns
I0101 02:51:30.465708 31016 leveldb.cpp:271] Iterated through 0 keys in the db in 455ns
I0101 02:51:30.465745 31016 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0101 02:51:30.466296 31040 recover.cpp:447] Starting replica recovery
I0101 02:51:30.466660 31040 recover.cpp:473] Replica is in EMPTY status
I0101 02:51:30.467795 31040 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12835)@172.17.0.5:35106
I0101 02:51:30.468376 31035 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0101 02:51:30.468904 31039 recover.cpp:564] Updating replica status to STARTING
I0101 02:51:30.469902 31042 master.cpp:365] Master 4703c9fb-0889-4c5c-868d-f9a2e0b2694d (9e617c76a5a5) started on 172.17.0.5:35106
I0101 02:51:30.469926 31042 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ErTvL4/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/ErTvL4/master" --zk_session_timeout="10secs"
I0101 02:51:30.470233 31042 master.cpp:414] Master allowing unauthenticated frameworks to register
I0101 02:51:30.470247 31042 master.cpp:417] Master only allowing authenticated slaves to register
I0101 02:51:30.470255 31042 credentials.hpp:35] Loading credentials for authentication from '/tmp/ErTvL4/credentials'
I0101 02:51:30.470527 31042 master.cpp:456] Using default 'crammd5' authenticator
I0101 02:51:30.470701 31042 master.cpp:493] Authorization enabled
I0101 02:51:30.470886 31045 hierarchical.cpp:147] Initialized hierarchical allocator process
I0101 02:51:30.470882 31047 whitelist_watcher.cpp:77] No whitelist given
I0101 02:51:30.472751 31050 master.cpp:1629] The newly elected leader is master@172.17.0.5:35106 with id 4703c9fb-0889-4c5c-868d-f9a2e0b2694d
I0101 02:51:30.472791 31050 master.cpp:1642] Elected as the leading master!
I0101 02:51:30.472810 31050 master.cpp:1387] Recovering from registrar
I0101 02:51:30.472959 31041 registrar.cpp:307] Recovering registrar
I0101 02:51:30.504971 31046 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 35.897014ms
I0101 02:51:30.505010 31046 replica.cpp:320] Persisted replica status to STARTING
I0101 02:51:30.505281 31047 recover.cpp:473] Replica is in STARTING status
I0101 02:51:30.506242 31035 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12836)@172.17.0.5:35106
I0101 02:51:30.506528 31048 recover.cpp:193] Received a recover response from a replica in STARTING status
I0101 02:51:30.507068 31047 recover.cpp:564] Updating replica status to VOTING
I0101 02:51:30.546898 31036 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.637344ms
I0101 02:51:30.546943 31036 replica.cpp:320] Persisted replica status to VOTING
I0101 02:51:30.547083 31039 recover.cpp:578] Successfully joined the Paxos group
I0101 02:51:30.547333 31039 recover.cpp:462] Recover process terminated
I0101 02:51:30.547840 31040 log.cpp:659] Attempting to start the writer
I0101 02:51:30.549192 31035 replica.cpp:493] Replica received implicit promise request from (12837)@172.17.0.5:35106 with proposal 1
I0101 02:51:30.588580 31035 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.347428ms
I0101 02:51:30.588637 31035 replica.cpp:342] Persisted promised to 1
I0101 02:51:30.589326 31050 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0101 02:51:30.590852 31050 replica.cpp:388] Replica received explicit promise request from (12838)@172.17.0.5:35106 for position 0 with proposal 2
I0101 02:51:30.630280 31050 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 39.372087ms
I0101 02:51:30.630319 31050 replica.cpp:712] Persisted action at 0
I0101 02:51:30.631727 31049 replica.cpp:537] Replica received write request for position 0 from (12839)@172.17.0.5:35106
I0101 02:51:30.631801 31049 leveldb.cpp:436] Reading position from leveldb took 30574ns
I0101 02:51:30.672179 31049 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.331142ms
I0101 02:51:30.672219 31049 replica.cpp:712] Persisted action at 0
I0101 02:51:30.672950 31050 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0101 02:51:30.713867 31050 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.822099ms
I0101 02:51:30.713907 31050 replica.cpp:712] Persisted action at 0
I0101 02:51:30.713932 31050 replica.cpp:697] Replica learned NOP action at position 0
I0101 02:51:30.714561 31047 log.cpp:675] Writer started with ending position 0
I0101 02:51:30.715791 31038 leveldb.cpp:436] Reading position from leveldb took 30867ns
I0101 02:51:30.716845 31044 registrar.cpp:340] Successfully fetched the registry (0B) in 243.806208ms
I0101 02:51:30.716965 31044 registrar.cpp:439] Applied 1 operations in 25979ns; attempting to update the 'registry'
I0101 02:51:30.717825 31045 log.cpp:683] Attempting to append 170 bytes to the log
I0101 02:51:30.717984 31037 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0101 02:51:30.718855 31049 replica.cpp:537] Replica received write request for position 1 from (12840)@172.17.0.5:35106
I0101 02:51:30.755714 31049 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 36.807508ms
I0101 02:51:30.755756 31049 replica.cpp:712] Persisted action at 1
I0101 02:51:30.756485 31041 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0101 02:51:30.797520 31041 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 40.998799ms
I0101 02:51:30.797560 31041 replica.cpp:712] Persisted action at 1
I0101 02:51:30.797582 31041 replica.cpp:697] Replica learned APPEND action at position 1
I0101 02:51:30.798801 31048 registrar.cpp:484] Successfully updated the 'registry' in 81.772032ms
I0101 02:51:30.798975 31048 registrar.cpp:370] Successfully recovered registrar
I0101 02:51:30.799059 31036 log.cpp:702] Attempting to truncate the log to 1
I0101 02:51:30.799260 31043 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0101 02:51:30.799866 31036 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0101 02:51:30.799952 31035 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0101 02:51:30.800333 31049 replica.cpp:537] Replica received write request for position 2 from (12841)@172.17.0.5:35106
I0101 02:51:30.839213 31049 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.835934ms
I0101 02:51:30.839252 31049 replica.cpp:712] Persisted action at 2
I0101 02:51:30.839951 31048 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0101 02:51:30.881055 31048 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 40.966791ms
I0101 02:51:30.881134 31048 leveldb.cpp:399] Deleting ~1 keys from leveldb took 39712ns
I0101 02:51:30.881162 31048 replica.cpp:712] Persisted action at 2
I0101 02:51:30.881186 31048 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0101 02:51:30.891137 31016 scheduler.cpp:154] Version: 0.27.0
I0101 02:51:30.891906 31042 scheduler.cpp:236] New master detected at master@172.17.0.5:35106
I0101 02:51:30.893247 31050 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:35106
I0101 02:51:30.895257 31042 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 02:51:30.895747 31037 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:35298
I0101 02:51:30.896103 31037 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0101 02:51:30.896162 31037 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0101 02:51:30.896435 31037 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0101 02:51:30.896806 31049 hierarchical.cpp:260] Added framework 4703c9fb-0889-4c5c-868d-f9a2e0b2694d-0000
I0101 02:51:30.896885 31049 hierarchical.cpp:1329] No resources available to allocate!
I0101 02:51:30.896930 31049 hierarchical.cpp:1423] No inverse offers to send out!
I0101 02:51:30.896932 31038 master.hpp:1659] Sending heartbeat to 4703c9fb-0889-4c5c-868d-f9a2e0b2694d-0000
I0101 02:51:30.896968 31049 hierarchical.cpp:1079] Performed allocation for 0 slaves in 131410ns
I0101 02:51:30.897650 31036 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:35106
I0101 02:51:30.898130 31036 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:35106
I0101 02:51:30.898718 31050 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0101 02:51:30.898753 31036 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:35106
I0101 02:51:30.900336 31038 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 02:51:30.900738 31043 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:35299
I0101 02:51:30.901001 31043 master.cpp:2636] Processing REQUEST call for framework 4703c9fb-0889-4c5c-868d-f9a2e0b2694d-0000 (default)
I0101 02:51:30.901197 31049 hierarchical.cpp:579] Received resource request from framework 4703c9fb-0889-4c5c-868d-f9a2e0b2694d-0000
I0101 02:51:30.901525 31041 master.cpp:930] Master terminating
I0101 02:51:30.901736 31036 hierarchical.cpp:321] Removed framework 4703c9fb-0889-4c5c-868d-f9a2e0b2694d-0000
E0101 02:51:30.902776 31042 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (591 ms)
[----------] 22 tests from ContentType/SchedulerTest (17023 ms total)
[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (722115 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-1451614251-20225
Untagged: mesos-1451614251-20225:latest
Deleted: be8f7b6dac35271edb7d7705644798331645673beaa70aa3e2bc636879d591d9
Deleted: 5503ce5f55da891079f83266490933e4139ca3d73b36366fc589b366b27aa51f
Deleted: f948f51b27de0af2ee9d2c8c697756d32f7868ca36e81d87c9deddd1e723acc3
Deleted: e35b8abcd6eeefb56c585bb277bcd5033d0b3c0fa3e32c3a838a3d5b2f2d225f
Deleted: 10ad0cf56eef33e47b36ca4beeb2248c95f0eb71dd677099049ce5dcd535b3ee
Deleted: a58c01ee19cb2dabd25dc88d09f47519291cb2e18aa4b8a07aed44f477d202ac
Deleted: c4ea7d3074979801855b6972a82c5f30bb480d8d5d1a5ff3c72fea78f88db209
Deleted: f471e4a8789a63ca22b055740a131125df7b26df30d70ee8bab26ec9d1f935a0
Deleted: 61d42e1c15581b6b488665aaa7abefc82807be70c542c33bf72f6fd4f2c92e4d
Deleted: 6bf4d1c2d0ded06fb1e12e8f0a7c0b27eb0676287aaa3a3c0ff906ce107aaf95
Deleted: 183a6e5c5f168a260d54669b3f0fc45636dfc067a7dcdcb2a35f11c64f364344
Deleted: 1f6334722ebf83422cf69cd463ab2a51b7f02b730c8efb993b6d2f0148210ded
Deleted: 2810da7276841e2e51b0d1f010aede3137e0102b412848b78b5514d1f2061149
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 #10515
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10515/>
------------------------------------------
[...truncated 165318 lines...]
[ OK ] ContentType/SchedulerTest.Message/1 (661 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0101 01:50:34.714423 31019 leveldb.cpp:174] Opened db in 119.445065ms
I0101 01:50:34.739823 31019 leveldb.cpp:181] Compacted db in 25.366169ms
I0101 01:50:34.739888 31019 leveldb.cpp:196] Created db iterator in 20152ns
I0101 01:50:34.739909 31019 leveldb.cpp:202] Seeked to beginning of db in 2145ns
I0101 01:50:34.739922 31019 leveldb.cpp:271] Iterated through 0 keys in the db in 432ns
I0101 01:50:34.739961 31019 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0101 01:50:34.740485 31049 recover.cpp:447] Starting replica recovery
I0101 01:50:34.740931 31049 recover.cpp:473] Replica is in EMPTY status
I0101 01:50:34.742090 31047 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12851)@172.17.0.5:56330
I0101 01:50:34.742545 31046 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0101 01:50:34.743006 31039 recover.cpp:564] Updating replica status to STARTING
I0101 01:50:34.743860 31050 master.cpp:365] Master e303a848-982d-492f-9afc-ad9a565cd127 (19ca6dd634d5) started on 172.17.0.5:56330
I0101 01:50:34.743878 31050 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/pJHPBD/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/pJHPBD/master" --zk_session_timeout="10secs"
I0101 01:50:34.744108 31050 master.cpp:414] Master allowing unauthenticated frameworks to register
I0101 01:50:34.744122 31050 master.cpp:417] Master only allowing authenticated slaves to register
I0101 01:50:34.744133 31050 credentials.hpp:35] Loading credentials for authentication from '/tmp/pJHPBD/credentials'
I0101 01:50:34.744354 31050 master.cpp:456] Using default 'crammd5' authenticator
I0101 01:50:34.744479 31050 master.cpp:493] Authorization enabled
I0101 01:50:34.744680 31052 hierarchical.cpp:147] Initialized hierarchical allocator process
I0101 01:50:34.744704 31040 whitelist_watcher.cpp:77] No whitelist given
I0101 01:50:34.746202 31043 master.cpp:1629] The newly elected leader is master@172.17.0.5:56330 with id e303a848-982d-492f-9afc-ad9a565cd127
I0101 01:50:34.746240 31043 master.cpp:1642] Elected as the leading master!
I0101 01:50:34.746268 31043 master.cpp:1387] Recovering from registrar
I0101 01:50:34.746450 31042 registrar.cpp:307] Recovering registrar
I0101 01:50:34.781347 31046 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 38.229648ms
I0101 01:50:34.781381 31046 replica.cpp:320] Persisted replica status to STARTING
I0101 01:50:34.781571 31044 recover.cpp:473] Replica is in STARTING status
I0101 01:50:34.782402 31048 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12852)@172.17.0.5:56330
I0101 01:50:34.782750 31042 recover.cpp:193] Received a recover response from a replica in STARTING status
I0101 01:50:34.783220 31045 recover.cpp:564] Updating replica status to VOTING
I0101 01:50:34.823223 31053 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.806455ms
I0101 01:50:34.823254 31053 replica.cpp:320] Persisted replica status to VOTING
I0101 01:50:34.823359 31046 recover.cpp:578] Successfully joined the Paxos group
I0101 01:50:34.823699 31046 recover.cpp:462] Recover process terminated
I0101 01:50:34.824188 31044 log.cpp:659] Attempting to start the writer
I0101 01:50:34.825569 31052 replica.cpp:493] Replica received implicit promise request from (12853)@172.17.0.5:56330 with proposal 1
I0101 01:50:34.865092 31052 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.463908ms
I0101 01:50:34.865136 31052 replica.cpp:342] Persisted promised to 1
I0101 01:50:34.865880 31044 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0101 01:50:34.867375 31046 replica.cpp:388] Replica received explicit promise request from (12854)@172.17.0.5:56330 for position 0 with proposal 2
I0101 01:50:34.906661 31046 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 39.232107ms
I0101 01:50:34.906709 31046 replica.cpp:712] Persisted action at 0
I0101 01:50:34.907943 31052 replica.cpp:537] Replica received write request for position 0 from (12855)@172.17.0.5:56330
I0101 01:50:34.908023 31052 leveldb.cpp:436] Reading position from leveldb took 35707ns
I0101 01:50:34.948550 31052 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.473465ms
I0101 01:50:34.948596 31052 replica.cpp:712] Persisted action at 0
I0101 01:50:34.949342 31039 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0101 01:50:34.990303 31039 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.824175ms
I0101 01:50:34.990348 31039 replica.cpp:712] Persisted action at 0
I0101 01:50:34.990373 31039 replica.cpp:697] Replica learned NOP action at position 0
I0101 01:50:34.991149 31044 log.cpp:675] Writer started with ending position 0
I0101 01:50:34.992460 31039 leveldb.cpp:436] Reading position from leveldb took 34532ns
I0101 01:50:34.993484 31045 registrar.cpp:340] Successfully fetched the registry (0B) in 246.976768ms
I0101 01:50:34.993633 31045 registrar.cpp:439] Applied 1 operations in 44088ns; attempting to update the 'registry'
I0101 01:50:34.994225 31047 log.cpp:683] Attempting to append 170 bytes to the log
I0101 01:50:34.994341 31053 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0101 01:50:34.995076 31052 replica.cpp:537] Replica received write request for position 1 from (12856)@172.17.0.5:56330
I0101 01:50:35.032207 31052 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 37.084815ms
I0101 01:50:35.032251 31052 replica.cpp:712] Persisted action at 1
I0101 01:50:35.033051 31046 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0101 01:50:35.073923 31046 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 40.828377ms
I0101 01:50:35.073966 31046 replica.cpp:712] Persisted action at 1
I0101 01:50:35.073997 31046 replica.cpp:697] Replica learned APPEND action at position 1
I0101 01:50:35.075155 31039 registrar.cpp:484] Successfully updated the 'registry' in 81.462016ms
I0101 01:50:35.075336 31039 registrar.cpp:370] Successfully recovered registrar
I0101 01:50:35.075403 31053 log.cpp:702] Attempting to truncate the log to 1
I0101 01:50:35.075549 31045 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0101 01:50:35.075990 31049 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0101 01:50:35.076084 31038 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0101 01:50:35.076666 31043 replica.cpp:537] Replica received write request for position 2 from (12857)@172.17.0.5:56330
I0101 01:50:35.112994 31043 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 36.280059ms
I0101 01:50:35.113037 31043 replica.cpp:712] Persisted action at 2
I0101 01:50:35.113809 31041 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0101 01:50:35.138252 31041 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.398162ms
I0101 01:50:35.138332 31041 leveldb.cpp:399] Deleting ~1 keys from leveldb took 41034ns
I0101 01:50:35.138356 31041 replica.cpp:712] Persisted action at 2
I0101 01:50:35.138378 31041 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0101 01:50:35.147125 31019 scheduler.cpp:154] Version: 0.27.0
I0101 01:50:35.147910 31038 scheduler.cpp:236] New master detected at master@172.17.0.5:56330
I0101 01:50:35.149142 31049 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:56330
I0101 01:50:35.151348 31038 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 01:50:35.151901 31050 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:55813
I0101 01:50:35.152144 31050 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0101 01:50:35.152231 31050 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0101 01:50:35.152586 31050 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0101 01:50:35.153074 31046 hierarchical.cpp:260] Added framework e303a848-982d-492f-9afc-ad9a565cd127-0000
I0101 01:50:35.153192 31046 hierarchical.cpp:1329] No resources available to allocate!
I0101 01:50:35.153122 31052 master.hpp:1659] Sending heartbeat to e303a848-982d-492f-9afc-ad9a565cd127-0000
I0101 01:50:35.153272 31046 hierarchical.cpp:1423] No inverse offers to send out!
I0101 01:50:35.153334 31046 hierarchical.cpp:1079] Performed allocation for 0 slaves in 221012ns
I0101 01:50:35.154041 31050 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:56330
I0101 01:50:35.154567 31050 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:56330
I0101 01:50:35.155364 31047 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0101 01:50:35.155423 31050 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:56330
I0101 01:50:35.157145 31047 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 01:50:35.157666 31046 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:55814
I0101 01:50:35.157781 31046 master.cpp:2636] Processing REQUEST call for framework e303a848-982d-492f-9afc-ad9a565cd127-0000 (default)
I0101 01:50:35.157968 31044 hierarchical.cpp:579] Received resource request from framework e303a848-982d-492f-9afc-ad9a565cd127-0000
I0101 01:50:35.158314 31042 master.cpp:930] Master terminating
I0101 01:50:35.158787 31043 hierarchical.cpp:321] Removed framework e303a848-982d-492f-9afc-ad9a565cd127-0000
E0101 01:50:35.159684 31043 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (572 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0101 01:50:35.231384 31019 leveldb.cpp:174] Opened db in 64.786741ms
I0101 01:50:35.248484 31019 leveldb.cpp:181] Compacted db in 17.057796ms
I0101 01:50:35.248548 31019 leveldb.cpp:196] Created db iterator in 18602ns
I0101 01:50:35.248570 31019 leveldb.cpp:202] Seeked to beginning of db in 2073ns
I0101 01:50:35.248581 31019 leveldb.cpp:271] Iterated through 0 keys in the db in 430ns
I0101 01:50:35.248652 31019 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0101 01:50:35.249169 31041 recover.cpp:447] Starting replica recovery
I0101 01:50:35.249510 31048 recover.cpp:473] Replica is in EMPTY status
I0101 01:50:35.250690 31053 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12865)@172.17.0.5:56330
I0101 01:50:35.250948 31049 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0101 01:50:35.251457 31048 recover.cpp:564] Updating replica status to STARTING
I0101 01:50:35.252481 31052 master.cpp:365] Master f80fa85a-ca80-49c0-ba33-885fcee1bdaf (19ca6dd634d5) started on 172.17.0.5:56330
I0101 01:50:35.252516 31052 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/AzqNAM/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/AzqNAM/master" --zk_session_timeout="10secs"
I0101 01:50:35.252841 31052 master.cpp:414] Master allowing unauthenticated frameworks to register
I0101 01:50:35.252853 31052 master.cpp:417] Master only allowing authenticated slaves to register
I0101 01:50:35.252861 31052 credentials.hpp:35] Loading credentials for authentication from '/tmp/AzqNAM/credentials'
I0101 01:50:35.253088 31052 master.cpp:456] Using default 'crammd5' authenticator
I0101 01:50:35.253203 31052 master.cpp:493] Authorization enabled
I0101 01:50:35.253357 31046 hierarchical.cpp:147] Initialized hierarchical allocator process
I0101 01:50:35.253367 31051 whitelist_watcher.cpp:77] No whitelist given
I0101 01:50:35.254952 31039 master.cpp:1629] The newly elected leader is master@172.17.0.5:56330 with id f80fa85a-ca80-49c0-ba33-885fcee1bdaf
I0101 01:50:35.254988 31039 master.cpp:1642] Elected as the leading master!
I0101 01:50:35.255008 31039 master.cpp:1387] Recovering from registrar
I0101 01:50:35.255211 31051 registrar.cpp:307] Recovering registrar
I0101 01:50:35.315554 31044 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 63.913019ms
I0101 01:50:35.315584 31044 replica.cpp:320] Persisted replica status to STARTING
I0101 01:50:35.315868 31039 recover.cpp:473] Replica is in STARTING status
I0101 01:50:35.316949 31050 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12866)@172.17.0.5:56330
I0101 01:50:35.317245 31040 recover.cpp:193] Received a recover response from a replica in STARTING status
I0101 01:50:35.317670 31050 recover.cpp:564] Updating replica status to VOTING
I0101 01:50:35.349133 31043 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.303361ms
I0101 01:50:35.349169 31043 replica.cpp:320] Persisted replica status to VOTING
I0101 01:50:35.349295 31043 recover.cpp:578] Successfully joined the Paxos group
I0101 01:50:35.349493 31043 recover.cpp:462] Recover process terminated
I0101 01:50:35.350066 31042 log.cpp:659] Attempting to start the writer
I0101 01:50:35.351258 31048 replica.cpp:493] Replica received implicit promise request from (12867)@172.17.0.5:56330 with proposal 1
I0101 01:50:35.374135 31048 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.8344ms
I0101 01:50:35.374177 31048 replica.cpp:342] Persisted promised to 1
I0101 01:50:35.374927 31049 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0101 01:50:35.376294 31042 replica.cpp:388] Replica received explicit promise request from (12868)@172.17.0.5:56330 for position 0 with proposal 2
I0101 01:50:35.424314 31042 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 47.964931ms
I0101 01:50:35.424360 31042 replica.cpp:712] Persisted action at 0
I0101 01:50:35.425681 31041 replica.cpp:537] Replica received write request for position 0 from (12869)@172.17.0.5:56330
I0101 01:50:35.425763 31041 leveldb.cpp:436] Reading position from leveldb took 37607ns
I0101 01:50:35.449462 31041 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.642465ms
I0101 01:50:35.449501 31041 replica.cpp:712] Persisted action at 0
I0101 01:50:35.450265 31050 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0101 01:50:35.474586 31050 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.230424ms
I0101 01:50:35.474644 31050 replica.cpp:712] Persisted action at 0
I0101 01:50:35.474668 31050 replica.cpp:697] Replica learned NOP action at position 0
I0101 01:50:35.475400 31050 log.cpp:675] Writer started with ending position 0
I0101 01:50:35.476511 31042 leveldb.cpp:436] Reading position from leveldb took 28616ns
I0101 01:50:35.477318 31044 registrar.cpp:340] Successfully fetched the registry (0B) in 222.048256ms
I0101 01:50:35.477433 31044 registrar.cpp:439] Applied 1 operations in 24385ns; attempting to update the 'registry'
I0101 01:50:35.478143 31050 log.cpp:683] Attempting to append 170 bytes to the log
I0101 01:50:35.478261 31051 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0101 01:50:35.479014 31046 replica.cpp:537] Replica received write request for position 1 from (12870)@172.17.0.5:56330
I0101 01:50:35.500236 31046 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 21.180913ms
I0101 01:50:35.500283 31046 replica.cpp:712] Persisted action at 1
I0101 01:50:35.501127 31043 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0101 01:50:35.525447 31043 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.282302ms
I0101 01:50:35.525490 31043 replica.cpp:712] Persisted action at 1
I0101 01:50:35.525527 31043 replica.cpp:697] Replica learned APPEND action at position 1
I0101 01:50:35.526679 31052 registrar.cpp:484] Successfully updated the 'registry' in 49.171968ms
I0101 01:50:35.526872 31052 registrar.cpp:370] Successfully recovered registrar
I0101 01:50:35.526950 31048 log.cpp:702] Attempting to truncate the log to 1
I0101 01:50:35.527222 31051 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0101 01:50:35.527346 31047 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0101 01:50:35.527371 31041 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0101 01:50:35.528280 31053 replica.cpp:537] Replica received write request for position 2 from (12871)@172.17.0.5:56330
I0101 01:50:35.550504 31053 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 22.17741ms
I0101 01:50:35.550544 31053 replica.cpp:712] Persisted action at 2
I0101 01:50:35.551321 31047 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0101 01:50:35.575587 31047 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.223364ms
I0101 01:50:35.575688 31047 leveldb.cpp:399] Deleting ~1 keys from leveldb took 41926ns
I0101 01:50:35.575716 31047 replica.cpp:712] Persisted action at 2
I0101 01:50:35.575737 31047 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0101 01:50:35.578289 31019 scheduler.cpp:154] Version: 0.27.0
I0101 01:50:35.579093 31041 scheduler.cpp:236] New master detected at master@172.17.0.5:56330
I0101 01:50:35.580519 31051 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:56330
I0101 01:50:35.582532 31042 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 01:50:35.583080 31049 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:55815
I0101 01:50:35.583380 31049 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0101 01:50:35.583434 31049 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0101 01:50:35.583688 31049 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0101 01:50:35.584090 31044 hierarchical.cpp:260] Added framework f80fa85a-ca80-49c0-ba33-885fcee1bdaf-0000
I0101 01:50:35.584151 31044 hierarchical.cpp:1329] No resources available to allocate!
I0101 01:50:35.584182 31044 hierarchical.cpp:1423] No inverse offers to send out!
I0101 01:50:35.584204 31044 hierarchical.cpp:1079] Performed allocation for 0 slaves in 90616ns
I0101 01:50:35.584213 31041 master.hpp:1659] Sending heartbeat to f80fa85a-ca80-49c0-ba33-885fcee1bdaf-0000
I0101 01:50:35.585105 31050 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:56330
I0101 01:50:35.585588 31050 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:56330
I0101 01:50:35.586066 31042 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0101 01:50:35.586107 31050 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:56330
I0101 01:50:35.587510 31052 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 01:50:35.587924 31048 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:55816
I0101 01:50:35.588130 31048 master.cpp:2636] Processing REQUEST call for framework f80fa85a-ca80-49c0-ba33-885fcee1bdaf-0000 (default)
I0101 01:50:35.588284 31040 hierarchical.cpp:579] Received resource request from framework f80fa85a-ca80-49c0-ba33-885fcee1bdaf-0000
I0101 01:50:35.588537 31043 master.cpp:930] Master terminating
I0101 01:50:35.588702 31048 hierarchical.cpp:321] Removed framework f80fa85a-ca80-49c0-ba33-885fcee1bdaf-0000
E0101 01:50:35.589692 31045 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (429 ms)
[----------] 22 tests from ContentType/SchedulerTest (15651 ms total)
[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (710505 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-1451610581-24737
Untagged: mesos-1451610581-24737:latest
Deleted: 5aa576111262c533f8898acf82f709810dcb4a8138f2c155419e0eea70b602e4
Deleted: 2d4af597dd4bf29a7d0f279b64dba68dc7fbcb43b24af76dded61661d4cc9191
Deleted: bc08c0bccf29eff0e63bf975e1807c58144c2b0141adea4d86dea8aecb3562bd
Deleted: cf56146591d4ff8756fc2b325f9ccf3eee76403eace3782289d5545a31fe4444
Deleted: 5357123609b14bf3bf886df45c78b0ad6d9a8f23317b44093bcf244824a75b13
Deleted: c66c79a844d3172e960767d7bca51361deaa49e3b6497a9c68750d0f262c20fb
Deleted: 60232e94f80b175b4812142de10556fd464f68e6d4620dcfc3974cc0d433b7c9
Deleted: 737faa06cd6f14000da98191b0cb276afe9832866f8531bea719f33853b23596
Deleted: 283db6b4e174e17bd37fa74658279074f016c5f99e88dafba6d268865e8ede5a
Deleted: d6ca1691404091973a3f006105fc972380aa9126e1726e65f221a2c753a02d4e
Deleted: 90c7ed1d64add0a41f2aa04f386d5bb97c829d405b893ec58c5e23e11e624eb3
Deleted: 877ce32eb524f3ddaad3a25862ad0e63d7241b4c6465cdb98e5a41847c074dcb
Deleted: a9df99460e8240f43c9305f05079d167cc4711e26fbbc19428c4e90ed6e6135f
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 #10514
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10514/>
------------------------------------------
[...truncated 165628 lines...]
[ OK ] ContentType/SchedulerTest.Message/1 (764 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0101 00:49:21.876232 31026 leveldb.cpp:174] Opened db in 118.927208ms
I0101 00:49:21.901763 31026 leveldb.cpp:181] Compacted db in 25.485159ms
I0101 00:49:21.901829 31026 leveldb.cpp:196] Created db iterator in 20465ns
I0101 00:49:21.901849 31026 leveldb.cpp:202] Seeked to beginning of db in 2212ns
I0101 00:49:21.901862 31026 leveldb.cpp:271] Iterated through 0 keys in the db in 343ns
I0101 00:49:21.901903 31026 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0101 00:49:21.902508 31056 recover.cpp:447] Starting replica recovery
I0101 00:49:21.902797 31056 recover.cpp:473] Replica is in EMPTY status
I0101 00:49:21.903877 31045 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12834)@172.17.0.5:34180
I0101 00:49:21.904398 31049 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0101 00:49:21.904839 31052 recover.cpp:564] Updating replica status to STARTING
I0101 00:49:21.905346 31057 master.cpp:365] Master 5b7db84e-c094-4392-9b96-1e23b11c96fb (819f7cf5ea90) started on 172.17.0.5:34180
I0101 00:49:21.905369 31057 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/52O3n6/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/52O3n6/master" --zk_session_timeout="10secs"
I0101 00:49:21.905691 31057 master.cpp:414] Master allowing unauthenticated frameworks to register
I0101 00:49:21.905711 31057 master.cpp:417] Master only allowing authenticated slaves to register
I0101 00:49:21.905721 31057 credentials.hpp:35] Loading credentials for authentication from '/tmp/52O3n6/credentials'
I0101 00:49:21.905972 31057 master.cpp:456] Using default 'crammd5' authenticator
I0101 00:49:21.906083 31057 master.cpp:493] Authorization enabled
I0101 00:49:21.906258 31046 whitelist_watcher.cpp:77] No whitelist given
I0101 00:49:21.906324 31050 hierarchical.cpp:147] Initialized hierarchical allocator process
I0101 00:49:21.907851 31052 master.cpp:1629] The newly elected leader is master@172.17.0.5:34180 with id 5b7db84e-c094-4392-9b96-1e23b11c96fb
I0101 00:49:21.907892 31052 master.cpp:1642] Elected as the leading master!
I0101 00:49:21.907923 31052 master.cpp:1387] Recovering from registrar
I0101 00:49:21.908115 31053 registrar.cpp:307] Recovering registrar
I0101 00:49:21.953102 31060 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 48.084123ms
I0101 00:49:21.953142 31060 replica.cpp:320] Persisted replica status to STARTING
I0101 00:49:21.953389 31047 recover.cpp:473] Replica is in STARTING status
I0101 00:49:21.954241 31057 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12835)@172.17.0.5:34180
I0101 00:49:21.954569 31050 recover.cpp:193] Received a recover response from a replica in STARTING status
I0101 00:49:21.955103 31059 recover.cpp:564] Updating replica status to VOTING
I0101 00:49:22.020431 31052 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 65.126702ms
I0101 00:49:22.020478 31052 replica.cpp:320] Persisted replica status to VOTING
I0101 00:49:22.020697 31052 recover.cpp:578] Successfully joined the Paxos group
I0101 00:49:22.021184 31052 recover.cpp:462] Recover process terminated
I0101 00:49:22.021399 31055 log.cpp:659] Attempting to start the writer
I0101 00:49:22.022799 31060 replica.cpp:493] Replica received implicit promise request from (12836)@172.17.0.5:34180 with proposal 1
I0101 00:49:22.062197 31060 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.358288ms
I0101 00:49:22.062242 31060 replica.cpp:342] Persisted promised to 1
I0101 00:49:22.062949 31046 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0101 00:49:22.064626 31060 replica.cpp:388] Replica received explicit promise request from (12837)@172.17.0.5:34180 for position 0 with proposal 2
I0101 00:49:22.099266 31060 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 34.59239ms
I0101 00:49:22.099311 31060 replica.cpp:712] Persisted action at 0
I0101 00:49:22.100484 31059 replica.cpp:537] Replica received write request for position 0 from (12838)@172.17.0.5:34180
I0101 00:49:22.100538 31059 leveldb.cpp:436] Reading position from leveldb took 25650ns
I0101 00:49:22.124295 31059 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.717246ms
I0101 00:49:22.124336 31059 replica.cpp:712] Persisted action at 0
I0101 00:49:22.125170 31055 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0101 00:49:22.141090 31055 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 15.876734ms
I0101 00:49:22.141129 31055 replica.cpp:712] Persisted action at 0
I0101 00:49:22.141150 31055 replica.cpp:697] Replica learned NOP action at position 0
I0101 00:49:22.141875 31049 log.cpp:675] Writer started with ending position 0
I0101 00:49:22.143049 31058 leveldb.cpp:436] Reading position from leveldb took 25613ns
I0101 00:49:22.144101 31050 registrar.cpp:340] Successfully fetched the registry (0B) in 235.919104ms
I0101 00:49:22.144206 31050 registrar.cpp:439] Applied 1 operations in 24984ns; attempting to update the 'registry'
I0101 00:49:22.144951 31054 log.cpp:683] Attempting to append 170 bytes to the log
I0101 00:49:22.145092 31056 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0101 00:49:22.145787 31059 replica.cpp:537] Replica received write request for position 1 from (12839)@172.17.0.5:34180
I0101 00:49:22.166268 31059 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 20.440513ms
I0101 00:49:22.166301 31059 replica.cpp:712] Persisted action at 1
I0101 00:49:22.167129 31045 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0101 00:49:22.191387 31045 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.220568ms
I0101 00:49:22.191428 31045 replica.cpp:712] Persisted action at 1
I0101 00:49:22.191452 31045 replica.cpp:697] Replica learned APPEND action at position 1
I0101 00:49:22.192767 31049 registrar.cpp:484] Successfully updated the 'registry' in 48.49408ms
I0101 00:49:22.192975 31049 registrar.cpp:370] Successfully recovered registrar
I0101 00:49:22.193048 31059 log.cpp:702] Attempting to truncate the log to 1
I0101 00:49:22.193188 31050 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0101 00:49:22.193486 31045 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0101 00:49:22.193527 31055 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0101 00:49:22.194265 31049 replica.cpp:537] Replica received write request for position 2 from (12840)@172.17.0.5:34180
I0101 00:49:22.216434 31049 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 22.126844ms
I0101 00:49:22.216475 31049 replica.cpp:712] Persisted action at 2
I0101 00:49:22.217185 31052 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0101 00:49:22.241539 31052 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.31575ms
I0101 00:49:22.241642 31052 leveldb.cpp:399] Deleting ~1 keys from leveldb took 64289ns
I0101 00:49:22.241674 31052 replica.cpp:712] Persisted action at 2
I0101 00:49:22.241703 31052 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0101 00:49:22.244766 31026 scheduler.cpp:154] Version: 0.27.0
I0101 00:49:22.245378 31059 scheduler.cpp:236] New master detected at master@172.17.0.5:34180
I0101 00:49:22.246682 31054 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:34180
I0101 00:49:22.248719 31055 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 00:49:22.249271 31058 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:37877
I0101 00:49:22.249480 31058 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0101 00:49:22.249546 31058 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0101 00:49:22.249922 31058 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0101 00:49:22.250365 31053 hierarchical.cpp:260] Added framework 5b7db84e-c094-4392-9b96-1e23b11c96fb-0000
I0101 00:49:22.250478 31058 master.hpp:1659] Sending heartbeat to 5b7db84e-c094-4392-9b96-1e23b11c96fb-0000
I0101 00:49:22.250569 31053 hierarchical.cpp:1329] No resources available to allocate!
I0101 00:49:22.250638 31053 hierarchical.cpp:1423] No inverse offers to send out!
I0101 00:49:22.250680 31053 hierarchical.cpp:1079] Performed allocation for 0 slaves in 158320ns
I0101 00:49:22.251365 31049 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:34180
I0101 00:49:22.251989 31049 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:34180
I0101 00:49:22.252691 31050 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0101 00:49:22.252835 31056 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:34180
I0101 00:49:22.254292 31055 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 00:49:22.254660 31048 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:37878
I0101 00:49:22.254778 31048 master.cpp:2636] Processing REQUEST call for framework 5b7db84e-c094-4392-9b96-1e23b11c96fb-0000 (default)
I0101 00:49:22.254955 31051 hierarchical.cpp:579] Received resource request from framework 5b7db84e-c094-4392-9b96-1e23b11c96fb-0000
I0101 00:49:22.255300 31049 master.cpp:930] Master terminating
I0101 00:49:22.255489 31045 hierarchical.cpp:321] Removed framework 5b7db84e-c094-4392-9b96-1e23b11c96fb-0000
E0101 00:49:22.256760 31050 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (506 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0101 00:49:22.387575 31026 leveldb.cpp:174] Opened db in 124.754541ms
I0101 00:49:22.421310 31026 leveldb.cpp:181] Compacted db in 33.662844ms
I0101 00:49:22.421375 31026 leveldb.cpp:196] Created db iterator in 19350ns
I0101 00:49:22.421396 31026 leveldb.cpp:202] Seeked to beginning of db in 1970ns
I0101 00:49:22.421407 31026 leveldb.cpp:271] Iterated through 0 keys in the db in 445ns
I0101 00:49:22.421443 31026 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0101 00:49:22.421991 31057 recover.cpp:447] Starting replica recovery
I0101 00:49:22.422366 31057 recover.cpp:473] Replica is in EMPTY status
I0101 00:49:22.423310 31050 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12848)@172.17.0.5:34180
I0101 00:49:22.423753 31048 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0101 00:49:22.424147 31053 recover.cpp:564] Updating replica status to STARTING
I0101 00:49:22.424696 31058 master.cpp:365] Master 0f57c874-e573-4ce0-a527-8ebb66c09d86 (819f7cf5ea90) started on 172.17.0.5:34180
I0101 00:49:22.424718 31058 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/fe6Pa3/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/fe6Pa3/master" --zk_session_timeout="10secs"
I0101 00:49:22.425003 31058 master.cpp:414] Master allowing unauthenticated frameworks to register
I0101 00:49:22.425017 31058 master.cpp:417] Master only allowing authenticated slaves to register
I0101 00:49:22.425029 31058 credentials.hpp:35] Loading credentials for authentication from '/tmp/fe6Pa3/credentials'
I0101 00:49:22.425240 31058 master.cpp:456] Using default 'crammd5' authenticator
I0101 00:49:22.425351 31058 master.cpp:493] Authorization enabled
I0101 00:49:22.425514 31057 hierarchical.cpp:147] Initialized hierarchical allocator process
I0101 00:49:22.425562 31049 whitelist_watcher.cpp:77] No whitelist given
I0101 00:49:22.427116 31056 master.cpp:1629] The newly elected leader is master@172.17.0.5:34180 with id 0f57c874-e573-4ce0-a527-8ebb66c09d86
I0101 00:49:22.427151 31056 master.cpp:1642] Elected as the leading master!
I0101 00:49:22.427170 31056 master.cpp:1387] Recovering from registrar
I0101 00:49:22.427295 31052 registrar.cpp:307] Recovering registrar
I0101 00:49:22.462865 31045 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 38.582092ms
I0101 00:49:22.462903 31045 replica.cpp:320] Persisted replica status to STARTING
I0101 00:49:22.463138 31045 recover.cpp:473] Replica is in STARTING status
I0101 00:49:22.464167 31045 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12849)@172.17.0.5:34180
I0101 00:49:22.464767 31047 recover.cpp:193] Received a recover response from a replica in STARTING status
I0101 00:49:22.465188 31046 recover.cpp:564] Updating replica status to VOTING
I0101 00:49:22.504545 31056 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.106925ms
I0101 00:49:22.504583 31056 replica.cpp:320] Persisted replica status to VOTING
I0101 00:49:22.504737 31045 recover.cpp:578] Successfully joined the Paxos group
I0101 00:49:22.505010 31045 recover.cpp:462] Recover process terminated
I0101 00:49:22.505466 31052 log.cpp:659] Attempting to start the writer
I0101 00:49:22.506851 31055 replica.cpp:493] Replica received implicit promise request from (12850)@172.17.0.5:34180 with proposal 1
I0101 00:49:22.546416 31055 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.524677ms
I0101 00:49:22.546461 31055 replica.cpp:342] Persisted promised to 1
I0101 00:49:22.547410 31053 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0101 00:49:22.548867 31059 replica.cpp:388] Replica received explicit promise request from (12851)@172.17.0.5:34180 for position 0 with proposal 2
I0101 00:49:22.588305 31059 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 39.38952ms
I0101 00:49:22.588351 31059 replica.cpp:712] Persisted action at 0
I0101 00:49:22.589800 31051 replica.cpp:537] Replica received write request for position 0 from (12852)@172.17.0.5:34180
I0101 00:49:22.589874 31051 leveldb.cpp:436] Reading position from leveldb took 30607ns
I0101 00:49:22.630121 31051 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.199575ms
I0101 00:49:22.630167 31051 replica.cpp:712] Persisted action at 0
I0101 00:49:22.630923 31046 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0101 00:49:22.671823 31046 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.866027ms
I0101 00:49:22.671867 31046 replica.cpp:712] Persisted action at 0
I0101 00:49:22.671892 31046 replica.cpp:697] Replica learned NOP action at position 0
I0101 00:49:22.672572 31056 log.cpp:675] Writer started with ending position 0
I0101 00:49:22.673398 31057 leveldb.cpp:436] Reading position from leveldb took 24003ns
I0101 00:49:22.674127 31057 registrar.cpp:340] Successfully fetched the registry (0B) in 246.78912ms
I0101 00:49:22.674216 31057 registrar.cpp:439] Applied 1 operations in 19236ns; attempting to update the 'registry'
I0101 00:49:22.674826 31058 log.cpp:683] Attempting to append 170 bytes to the log
I0101 00:49:22.674926 31052 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0101 00:49:22.675499 31055 replica.cpp:537] Replica received write request for position 1 from (12853)@172.17.0.5:34180
I0101 00:49:22.713634 31055 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 38.074108ms
I0101 00:49:22.713675 31055 replica.cpp:712] Persisted action at 1
I0101 00:49:22.714400 31059 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0101 00:49:22.755461 31059 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 41.031402ms
I0101 00:49:22.755507 31059 replica.cpp:712] Persisted action at 1
I0101 00:49:22.755532 31059 replica.cpp:697] Replica learned APPEND action at position 1
I0101 00:49:22.756669 31060 registrar.cpp:484] Successfully updated the 'registry' in 82.36288ms
I0101 00:49:22.756862 31060 registrar.cpp:370] Successfully recovered registrar
I0101 00:49:22.756929 31055 log.cpp:702] Attempting to truncate the log to 1
I0101 00:49:22.757102 31054 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0101 00:49:22.757467 31053 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0101 00:49:22.757503 31057 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0101 00:49:22.758054 31059 replica.cpp:537] Replica received write request for position 2 from (12854)@172.17.0.5:34180
I0101 00:49:22.797057 31059 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.969412ms
I0101 00:49:22.797097 31059 replica.cpp:712] Persisted action at 2
I0101 00:49:22.797906 31060 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0101 00:49:22.838856 31060 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 40.840241ms
I0101 00:49:22.838935 31060 leveldb.cpp:399] Deleting ~1 keys from leveldb took 40673ns
I0101 00:49:22.838963 31060 replica.cpp:712] Persisted action at 2
I0101 00:49:22.838985 31060 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0101 00:49:22.848783 31026 scheduler.cpp:154] Version: 0.27.0
I0101 00:49:22.849455 31053 scheduler.cpp:236] New master detected at master@172.17.0.5:34180
I0101 00:49:22.850706 31046 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:34180
I0101 00:49:22.852882 31056 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 00:49:22.853402 31050 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:37879
I0101 00:49:22.853835 31050 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0101 00:49:22.853902 31050 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0101 00:49:22.854219 31050 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0101 00:49:22.854651 31049 hierarchical.cpp:260] Added framework 0f57c874-e573-4ce0-a527-8ebb66c09d86-0000
I0101 00:49:22.854717 31049 hierarchical.cpp:1329] No resources available to allocate!
I0101 00:49:22.854764 31049 hierarchical.cpp:1423] No inverse offers to send out!
I0101 00:49:22.854764 31057 master.hpp:1659] Sending heartbeat to 0f57c874-e573-4ce0-a527-8ebb66c09d86-0000
I0101 00:49:22.854810 31049 hierarchical.cpp:1079] Performed allocation for 0 slaves in 127464ns
I0101 00:49:22.855856 31058 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:34180
I0101 00:49:22.856354 31058 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:34180
I0101 00:49:22.857062 31045 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0101 00:49:22.857125 31058 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:34180
I0101 00:49:22.859046 31055 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0101 00:49:22.859540 31059 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:37880
I0101 00:49:22.859810 31059 master.cpp:2636] Processing REQUEST call for framework 0f57c874-e573-4ce0-a527-8ebb66c09d86-0000 (default)
I0101 00:49:22.859993 31057 hierarchical.cpp:579] Received resource request from framework 0f57c874-e573-4ce0-a527-8ebb66c09d86-0000
I0101 00:49:22.860352 31055 master.cpp:930] Master terminating
I0101 00:49:22.860565 31060 hierarchical.cpp:321] Removed framework 0f57c874-e573-4ce0-a527-8ebb66c09d86-0000
E0101 00:49:22.862131 31054 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (605 ms)
[----------] 22 tests from ContentType/SchedulerTest (15240 ms total)
[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (716060 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-1451606979-2558
Untagged: mesos-1451606979-2558:latest
Deleted: 7b52976bd4d53b2dc2580c5337043b378909bea92de9303b6babcbd26c65c6a5
Deleted: 9eeeac1e192b9671e52a82b5b99bbf382d76c86c3dac24d9945241c6d2abb95e
Deleted: 3d6e534539f26c7905400a3f2ae9a17634a6bced3616b999b51477ffa8124a89
Deleted: 66d6ab2389a690e40e06caadbeff2b3a6f0851d5c7c5e6c48ef286bd145fb474
Deleted: 9a61460d04aad3fe24d6aa7ccfe9fa540e9d4e850e1718dfdde99e7223f1054a
Deleted: 463c6c04b8b19190b835a36cd54792a4929a726f1386b3e14f5f57a77db572b7
Deleted: 369506d08c4b9773f485cecad109cc2d3de9a1a0a2dc79d341fe5d13f873f9de
Deleted: 0a243ffd1f1c4bf7f6d827073e9250de48f4bb0d6caf7dab930fd7924716f3fb
Deleted: c5324bb80dc40e4da1dd954103e24e9abf7c8d6dfa6dcb534e6c7baeceb3802e
Deleted: 6428631dbeec097c7cf950a1bc22e42f2c8064cdce1410df12eb527347bdd4a4
Deleted: 20f0013f1aa6419c35b20ae358ac410663512704c521fc206ebbf342ab7ea4c3
Deleted: 0166306a7475ab8a46b7e8d51c6bf9e71cc701973599e976fccd3a530ebe38d4
Deleted: 606ed6dcbf919c0c1c05d1632849052c627f0be332b0acc431c5d88c86eadf75
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 #10513
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10513/>
------------------------------------------
[...truncated 165575 lines...]
[ OK ] ContentType/SchedulerTest.Message/1 (719 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I1231 23:47:28.553436 31024 leveldb.cpp:174] Opened db in 111.167234ms
I1231 23:47:28.576591 31024 leveldb.cpp:181] Compacted db in 23.109083ms
I1231 23:47:28.576653 31024 leveldb.cpp:196] Created db iterator in 18165ns
I1231 23:47:28.576671 31024 leveldb.cpp:202] Seeked to beginning of db in 1985ns
I1231 23:47:28.576684 31024 leveldb.cpp:271] Iterated through 0 keys in the db in 337ns
I1231 23:47:28.576720 31024 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1231 23:47:28.577186 31054 recover.cpp:447] Starting replica recovery
I1231 23:47:28.577430 31054 recover.cpp:473] Replica is in EMPTY status
I1231 23:47:28.578764 31044 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12845)@172.17.0.2:50890
I1231 23:47:28.579447 31043 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1231 23:47:28.579949 31053 recover.cpp:564] Updating replica status to STARTING
I1231 23:47:28.580968 31058 master.cpp:365] Master 3a4b0bf2-3c72-4e62-83df-d74fe6eacd0e (07c596ca3265) started on 172.17.0.2:50890
I1231 23:47:28.581061 31058 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/93Zlxj/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/93Zlxj/master" --zk_session_timeout="10secs"
I1231 23:47:28.581418 31058 master.cpp:414] Master allowing unauthenticated frameworks to register
I1231 23:47:28.581430 31058 master.cpp:417] Master only allowing authenticated slaves to register
I1231 23:47:28.581439 31058 credentials.hpp:35] Loading credentials for authentication from '/tmp/93Zlxj/credentials'
I1231 23:47:28.581707 31058 master.cpp:456] Using default 'crammd5' authenticator
I1231 23:47:28.581841 31058 master.cpp:493] Authorization enabled
I1231 23:47:28.582026 31044 hierarchical.cpp:147] Initialized hierarchical allocator process
I1231 23:47:28.582044 31054 whitelist_watcher.cpp:77] No whitelist given
I1231 23:47:28.583968 31049 master.cpp:1629] The newly elected leader is master@172.17.0.2:50890 with id 3a4b0bf2-3c72-4e62-83df-d74fe6eacd0e
I1231 23:47:28.584005 31049 master.cpp:1642] Elected as the leading master!
I1231 23:47:28.584023 31049 master.cpp:1387] Recovering from registrar
I1231 23:47:28.584292 31055 registrar.cpp:307] Recovering registrar
I1231 23:47:28.617528 31057 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 37.411746ms
I1231 23:47:28.617574 31057 replica.cpp:320] Persisted replica status to STARTING
I1231 23:47:28.617832 31050 recover.cpp:473] Replica is in STARTING status
I1231 23:47:28.618597 31052 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12846)@172.17.0.2:50890
I1231 23:47:28.618904 31045 recover.cpp:193] Received a recover response from a replica in STARTING status
I1231 23:47:28.619285 31051 recover.cpp:564] Updating replica status to VOTING
I1231 23:47:28.650974 31048 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.52614ms
I1231 23:47:28.651003 31048 replica.cpp:320] Persisted replica status to VOTING
I1231 23:47:28.651113 31054 recover.cpp:578] Successfully joined the Paxos group
I1231 23:47:28.651410 31054 recover.cpp:462] Recover process terminated
I1231 23:47:28.651862 31052 log.cpp:659] Attempting to start the writer
I1231 23:47:28.653262 31046 replica.cpp:493] Replica received implicit promise request from (12847)@172.17.0.2:50890 with proposal 1
I1231 23:47:28.676044 31046 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.740287ms
I1231 23:47:28.676085 31046 replica.cpp:342] Persisted promised to 1
I1231 23:47:28.676976 31047 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1231 23:47:28.678486 31056 replica.cpp:388] Replica received explicit promise request from (12848)@172.17.0.2:50890 for position 0 with proposal 2
I1231 23:47:28.701148 31056 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.587096ms
I1231 23:47:28.701185 31056 replica.cpp:712] Persisted action at 0
I1231 23:47:28.702427 31046 replica.cpp:537] Replica received write request for position 0 from (12849)@172.17.0.2:50890
I1231 23:47:28.702492 31046 leveldb.cpp:436] Reading position from leveldb took 28799ns
I1231 23:47:28.726279 31046 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.741848ms
I1231 23:47:28.726320 31046 replica.cpp:712] Persisted action at 0
I1231 23:47:28.726990 31046 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I1231 23:47:28.743021 31046 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 15.991563ms
I1231 23:47:28.743060 31046 replica.cpp:712] Persisted action at 0
I1231 23:47:28.743082 31046 replica.cpp:697] Replica learned NOP action at position 0
I1231 23:47:28.743713 31054 log.cpp:675] Writer started with ending position 0
I1231 23:47:28.744899 31052 leveldb.cpp:436] Reading position from leveldb took 36691ns
I1231 23:47:28.745853 31046 registrar.cpp:340] Successfully fetched the registry (0B) in 161.416192ms
I1231 23:47:28.745972 31046 registrar.cpp:439] Applied 1 operations in 24779ns; attempting to update the 'registry'
I1231 23:47:28.746995 31054 log.cpp:683] Attempting to append 170 bytes to the log
I1231 23:47:28.747182 31045 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1231 23:47:28.747928 31043 replica.cpp:537] Replica received write request for position 1 from (12850)@172.17.0.2:50890
I1231 23:47:28.768276 31043 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 20.307038ms
I1231 23:47:28.768311 31043 replica.cpp:712] Persisted action at 1
I1231 23:47:28.769024 31057 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I1231 23:47:28.793334 31057 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.271333ms
I1231 23:47:28.793373 31057 replica.cpp:712] Persisted action at 1
I1231 23:47:28.793395 31057 replica.cpp:697] Replica learned APPEND action at position 1
I1231 23:47:28.794513 31053 registrar.cpp:484] Successfully updated the 'registry' in 48.473856ms
I1231 23:47:28.794677 31053 registrar.cpp:370] Successfully recovered registrar
I1231 23:47:28.794808 31045 log.cpp:702] Attempting to truncate the log to 1
I1231 23:47:28.795099 31046 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1231 23:47:28.795285 31051 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I1231 23:47:28.795347 31054 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I1231 23:47:28.796079 31048 replica.cpp:537] Replica received write request for position 2 from (12851)@172.17.0.2:50890
I1231 23:47:28.818461 31048 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 22.335384ms
I1231 23:47:28.818506 31048 replica.cpp:712] Persisted action at 2
I1231 23:47:28.819280 31047 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I1231 23:47:28.843498 31047 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.177626ms
I1231 23:47:28.843575 31047 leveldb.cpp:399] Deleting ~1 keys from leveldb took 39434ns
I1231 23:47:28.843601 31047 replica.cpp:712] Persisted action at 2
I1231 23:47:28.843624 31047 replica.cpp:697] Replica learned TRUNCATE action at position 2
I1231 23:47:28.846297 31024 scheduler.cpp:154] Version: 0.27.0
I1231 23:47:28.846966 31046 scheduler.cpp:236] New master detected at master@172.17.0.2:50890
I1231 23:47:28.847869 31050 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:50890
I1231 23:47:28.849293 31046 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1231 23:47:28.849642 31044 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:51896
I1231 23:47:28.849793 31044 master.cpp:1891] Received subscription request for HTTP framework 'default'
I1231 23:47:28.849840 31044 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1231 23:47:28.850045 31044 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1231 23:47:28.850404 31058 hierarchical.cpp:260] Added framework 3a4b0bf2-3c72-4e62-83df-d74fe6eacd0e-0000
I1231 23:47:28.850458 31047 master.hpp:1659] Sending heartbeat to 3a4b0bf2-3c72-4e62-83df-d74fe6eacd0e-0000
I1231 23:47:28.850472 31058 hierarchical.cpp:1329] No resources available to allocate!
I1231 23:47:28.850584 31058 hierarchical.cpp:1423] No inverse offers to send out!
I1231 23:47:28.850620 31058 hierarchical.cpp:1079] Performed allocation for 0 slaves in 185685ns
I1231 23:47:28.851346 31047 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:50890
I1231 23:47:28.851830 31047 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:50890
I1231 23:47:28.852637 31053 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I1231 23:47:28.852727 31047 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:50890
I1231 23:47:28.854274 31043 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1231 23:47:28.854781 31053 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:51897
I1231 23:47:28.854914 31053 master.cpp:2636] Processing REQUEST call for framework 3a4b0bf2-3c72-4e62-83df-d74fe6eacd0e-0000 (default)
I1231 23:47:28.855082 31052 hierarchical.cpp:579] Received resource request from framework 3a4b0bf2-3c72-4e62-83df-d74fe6eacd0e-0000
I1231 23:47:28.855443 31055 master.cpp:930] Master terminating
I1231 23:47:28.855659 31058 hierarchical.cpp:321] Removed framework 3a4b0bf2-3c72-4e62-83df-d74fe6eacd0e-0000
E1231 23:47:28.856966 31056 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (421 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I1231 23:47:28.996193 31024 leveldb.cpp:174] Opened db in 132.158189ms
I1231 23:47:29.046699 31024 leveldb.cpp:181] Compacted db in 50.459214ms
I1231 23:47:29.046761 31024 leveldb.cpp:196] Created db iterator in 16712ns
I1231 23:47:29.046780 31024 leveldb.cpp:202] Seeked to beginning of db in 2107ns
I1231 23:47:29.046792 31024 leveldb.cpp:271] Iterated through 0 keys in the db in 267ns
I1231 23:47:29.046829 31024 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1231 23:47:29.047379 31048 recover.cpp:447] Starting replica recovery
I1231 23:47:29.047832 31058 recover.cpp:473] Replica is in EMPTY status
I1231 23:47:29.049191 31050 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12859)@172.17.0.2:50890
I1231 23:47:29.049468 31056 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1231 23:47:29.049887 31045 master.cpp:365] Master 0863e683-ae95-4b7a-b69d-a4a796ce5cc4 (07c596ca3265) started on 172.17.0.2:50890
I1231 23:47:29.049906 31048 recover.cpp:564] Updating replica status to STARTING
I1231 23:47:29.049906 31045 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/dDn68E/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/dDn68E/master" --zk_session_timeout="10secs"
I1231 23:47:29.050190 31045 master.cpp:414] Master allowing unauthenticated frameworks to register
I1231 23:47:29.050202 31045 master.cpp:417] Master only allowing authenticated slaves to register
I1231 23:47:29.050214 31045 credentials.hpp:35] Loading credentials for authentication from '/tmp/dDn68E/credentials'
I1231 23:47:29.050459 31045 master.cpp:456] Using default 'crammd5' authenticator
I1231 23:47:29.050570 31045 master.cpp:493] Authorization enabled
I1231 23:47:29.050717 31049 hierarchical.cpp:147] Initialized hierarchical allocator process
I1231 23:47:29.050755 31051 whitelist_watcher.cpp:77] No whitelist given
I1231 23:47:29.052069 31058 master.cpp:1629] The newly elected leader is master@172.17.0.2:50890 with id 0863e683-ae95-4b7a-b69d-a4a796ce5cc4
I1231 23:47:29.052101 31058 master.cpp:1642] Elected as the leading master!
I1231 23:47:29.052121 31058 master.cpp:1387] Recovering from registrar
I1231 23:47:29.052289 31047 registrar.cpp:307] Recovering registrar
I1231 23:47:29.077455 31055 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 27.215693ms
I1231 23:47:29.077493 31055 replica.cpp:320] Persisted replica status to STARTING
I1231 23:47:29.077776 31049 recover.cpp:473] Replica is in STARTING status
I1231 23:47:29.078853 31046 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12860)@172.17.0.2:50890
I1231 23:47:29.079190 31045 recover.cpp:193] Received a recover response from a replica in STARTING status
I1231 23:47:29.079720 31044 recover.cpp:564] Updating replica status to VOTING
I1231 23:47:29.096534 31058 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 16.587081ms
I1231 23:47:29.096571 31058 replica.cpp:320] Persisted replica status to VOTING
I1231 23:47:29.096719 31053 recover.cpp:578] Successfully joined the Paxos group
I1231 23:47:29.097033 31053 recover.cpp:462] Recover process terminated
I1231 23:47:29.097455 31044 log.cpp:659] Attempting to start the writer
I1231 23:47:29.098719 31045 replica.cpp:493] Replica received implicit promise request from (12861)@172.17.0.2:50890 with proposal 1
I1231 23:47:29.121686 31045 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.922537ms
I1231 23:47:29.121722 31045 replica.cpp:342] Persisted promised to 1
I1231 23:47:29.122437 31045 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1231 23:47:29.123780 31045 replica.cpp:388] Replica received explicit promise request from (12862)@172.17.0.2:50890 for position 0 with proposal 2
I1231 23:47:29.146792 31045 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.967645ms
I1231 23:47:29.146829 31045 replica.cpp:712] Persisted action at 0
I1231 23:47:29.148341 31053 replica.cpp:537] Replica received write request for position 0 from (12863)@172.17.0.2:50890
I1231 23:47:29.148406 31053 leveldb.cpp:436] Reading position from leveldb took 27452ns
I1231 23:47:29.177460 31053 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 29.011393ms
I1231 23:47:29.177496 31053 replica.cpp:712] Persisted action at 0
I1231 23:47:29.178267 31049 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I1231 23:47:29.219207 31049 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.900881ms
I1231 23:47:29.219245 31049 replica.cpp:712] Persisted action at 0
I1231 23:47:29.219266 31049 replica.cpp:697] Replica learned NOP action at position 0
I1231 23:47:29.220000 31058 log.cpp:675] Writer started with ending position 0
I1231 23:47:29.221173 31050 leveldb.cpp:436] Reading position from leveldb took 46302ns
I1231 23:47:29.222185 31053 registrar.cpp:340] Successfully fetched the registry (0B) in 169.850112ms
I1231 23:47:29.222316 31053 registrar.cpp:439] Applied 1 operations in 34414ns; attempting to update the 'registry'
I1231 23:47:29.223086 31054 log.cpp:683] Attempting to append 170 bytes to the log
I1231 23:47:29.223242 31055 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1231 23:47:29.224093 31057 replica.cpp:537] Replica received write request for position 1 from (12864)@172.17.0.2:50890
I1231 23:47:29.269531 31057 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 45.353581ms
I1231 23:47:29.269577 31057 replica.cpp:712] Persisted action at 1
I1231 23:47:29.270526 31045 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I1231 23:47:29.311197 31045 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 40.631803ms
I1231 23:47:29.311236 31045 replica.cpp:712] Persisted action at 1
I1231 23:47:29.311259 31045 replica.cpp:697] Replica learned APPEND action at position 1
I1231 23:47:29.312547 31054 registrar.cpp:484] Successfully updated the 'registry' in 90.167808ms
I1231 23:47:29.312692 31054 registrar.cpp:370] Successfully recovered registrar
I1231 23:47:29.312733 31058 log.cpp:702] Attempting to truncate the log to 1
I1231 23:47:29.312955 31058 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1231 23:47:29.313333 31054 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I1231 23:47:29.313372 31049 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I1231 23:47:29.314280 31043 replica.cpp:537] Replica received write request for position 2 from (12865)@172.17.0.2:50890
I1231 23:47:29.352938 31043 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.610639ms
I1231 23:47:29.352977 31043 replica.cpp:712] Persisted action at 2
I1231 23:47:29.353785 31054 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I1231 23:47:29.394717 31054 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 40.88918ms
I1231 23:47:29.394798 31054 leveldb.cpp:399] Deleting ~1 keys from leveldb took 41192ns
I1231 23:47:29.394831 31054 replica.cpp:712] Persisted action at 2
I1231 23:47:29.394855 31054 replica.cpp:697] Replica learned TRUNCATE action at position 2
I1231 23:47:29.404682 31024 scheduler.cpp:154] Version: 0.27.0
I1231 23:47:29.405357 31045 scheduler.cpp:236] New master detected at master@172.17.0.2:50890
I1231 23:47:29.406576 31048 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:50890
I1231 23:47:29.408710 31049 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1231 23:47:29.409246 31054 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:51898
I1231 23:47:29.409654 31054 master.cpp:1891] Received subscription request for HTTP framework 'default'
I1231 23:47:29.409729 31054 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1231 23:47:29.410053 31054 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1231 23:47:29.410459 31058 hierarchical.cpp:260] Added framework 0863e683-ae95-4b7a-b69d-a4a796ce5cc4-0000
I1231 23:47:29.410518 31058 hierarchical.cpp:1329] No resources available to allocate!
I1231 23:47:29.410682 31058 hierarchical.cpp:1423] No inverse offers to send out!
I1231 23:47:29.410837 31058 hierarchical.cpp:1079] Performed allocation for 0 slaves in 347434ns
I1231 23:47:29.410594 31055 master.hpp:1659] Sending heartbeat to 0863e683-ae95-4b7a-b69d-a4a796ce5cc4-0000
I1231 23:47:29.411703 31046 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:50890
I1231 23:47:29.412174 31046 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:50890
I1231 23:47:29.412693 31045 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I1231 23:47:29.412735 31046 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:50890
I1231 23:47:29.414145 31048 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1231 23:47:29.414568 31047 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:51899
I1231 23:47:29.414777 31047 master.cpp:2636] Processing REQUEST call for framework 0863e683-ae95-4b7a-b69d-a4a796ce5cc4-0000 (default)
I1231 23:47:29.414969 31049 hierarchical.cpp:579] Received resource request from framework 0863e683-ae95-4b7a-b69d-a4a796ce5cc4-0000
I1231 23:47:29.415200 31050 master.cpp:930] Master terminating
I1231 23:47:29.415365 31055 hierarchical.cpp:321] Removed framework 0863e683-ae95-4b7a-b69d-a4a796ce5cc4-0000
E1231 23:47:29.416465 31045 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (558 ms)
[----------] 22 tests from ContentType/SchedulerTest (15540 ms total)
[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (725579 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-1451603388-4765
Untagged: mesos-1451603388-4765:latest
Deleted: ef4e22cd1f68dba7d3b16876e6968cb7e2fe42d6c6b86f2edd9d9cbe77368bcf
Deleted: 82bc4334e515938188fd5ddc1d9db1316e71fd7f4c9fa982a68518a963501585
Deleted: c9869eaa43d86a5afb10033c25d36aa175094bf74c8f4ccc0543dab146737fb2
Deleted: 272c0c8a652199c3c0ba95769becf8a65b2353a3eba9d0775e7cdef834ae6356
Deleted: 23e91616f2dc892f9f8c1b8803877bed1a3152af721e094962efdb6e49d9454a
Deleted: 5e3205f9c799e98e514142f70a132c6df23754afcb26b0635b256f1a290b84e7
Deleted: 1a1c13bdff01c7339653d97f24db65276324bde849895636434b1fd754e8bd6b
Deleted: ba9c6d7347e381698e74cf9a7f6bcd3d7efbefe3a97da5e57adaf2f2b904d8ad
Deleted: 3e6f9b4ee93ae2d1c667eadbf477e40856fbaaedeb47337cf7261c887ba91387
Deleted: 3ba962b557d0638ceb5ba0287d28fd53ee1c0b97f2fcdd86bc64b7beb5b5e7f7
Deleted: 8747a47fac6fb36fab48aa21b301b8048be880d2543d2b60fe34ea52d4e936af
Deleted: 493777a46fa938bf6ace8595d033a5848113347c87d72072471847cfe2d5b046
Deleted: ff949f663107a2e010c1837006435ca81e41d669bb96ab5e12eaa840ebf5fe63
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 #10512
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10512/>
------------------------------------------
[...truncated 165598 lines...]
[ RUN ] ContentType/SchedulerTest.Request/0
I1231 21:52:39.523089 31022 leveldb.cpp:174] Opened db in 143.445036ms
I1231 21:52:39.573640 31022 leveldb.cpp:181] Compacted db in 50.509232ms
I1231 21:52:39.573705 31022 leveldb.cpp:196] Created db iterator in 20397ns
I1231 21:52:39.573725 31022 leveldb.cpp:202] Seeked to beginning of db in 2145ns
I1231 21:52:39.573736 31022 leveldb.cpp:271] Iterated through 0 keys in the db in 450ns
I1231 21:52:39.573776 31022 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1231 21:52:39.574225 31047 recover.cpp:447] Starting replica recovery
I1231 21:52:39.574643 31047 recover.cpp:473] Replica is in EMPTY status
I1231 21:52:39.575687 31042 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12829)@172.17.0.2:53514
I1231 21:52:39.576179 31041 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1231 21:52:39.576596 31048 recover.cpp:564] Updating replica status to STARTING
I1231 21:52:39.577189 31051 master.cpp:365] Master c9e3aebe-4be7-414a-92de-9bd5b1785f3f (c39174bc7eb8) started on 172.17.0.2:53514
I1231 21:52:39.577240 31051 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/Cdbyxq/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/Cdbyxq/master" --zk_session_timeout="10secs"
I1231 21:52:39.577584 31051 master.cpp:414] Master allowing unauthenticated frameworks to register
I1231 21:52:39.577607 31051 master.cpp:417] Master only allowing authenticated slaves to register
I1231 21:52:39.577625 31051 credentials.hpp:35] Loading credentials for authentication from '/tmp/Cdbyxq/credentials'
I1231 21:52:39.577899 31051 master.cpp:456] Using default 'crammd5' authenticator
I1231 21:52:39.578049 31051 master.cpp:493] Authorization enabled
I1231 21:52:39.578244 31043 hierarchical.cpp:147] Initialized hierarchical allocator process
I1231 21:52:39.578248 31049 whitelist_watcher.cpp:77] No whitelist given
I1231 21:52:39.580229 31054 master.cpp:1629] The newly elected leader is master@172.17.0.2:53514 with id c9e3aebe-4be7-414a-92de-9bd5b1785f3f
I1231 21:52:39.580263 31054 master.cpp:1642] Elected as the leading master!
I1231 21:52:39.580283 31054 master.cpp:1387] Recovering from registrar
I1231 21:52:39.580442 31044 registrar.cpp:307] Recovering registrar
I1231 21:52:39.621006 31055 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 44.299396ms
I1231 21:52:39.621043 31055 replica.cpp:320] Persisted replica status to STARTING
I1231 21:52:39.621276 31045 recover.cpp:473] Replica is in STARTING status
I1231 21:52:39.622189 31050 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12830)@172.17.0.2:53514
I1231 21:52:39.622475 31041 recover.cpp:193] Received a recover response from a replica in STARTING status
I1231 21:52:39.623108 31047 recover.cpp:564] Updating replica status to VOTING
2015-12-31 21:52:39,630:31022(0x2ba4b881d700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46494] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I1231 21:52:39.654593 31053 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.280342ms
I1231 21:52:39.654638 31053 replica.cpp:320] Persisted replica status to VOTING
I1231 21:52:39.654767 31053 recover.cpp:578] Successfully joined the Paxos group
I1231 21:52:39.654996 31053 recover.cpp:462] Recover process terminated
I1231 21:52:39.655592 31055 log.cpp:659] Attempting to start the writer
I1231 21:52:39.657153 31055 replica.cpp:493] Replica received implicit promise request from (12831)@172.17.0.2:53514 with proposal 1
I1231 21:52:39.679615 31055 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.423339ms
I1231 21:52:39.679659 31055 replica.cpp:342] Persisted promised to 1
I1231 21:52:39.680408 31041 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1231 21:52:39.681814 31046 replica.cpp:388] Replica received explicit promise request from (12832)@172.17.0.2:53514 for position 0 with proposal 2
I1231 21:52:39.704716 31046 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.853589ms
I1231 21:52:39.704757 31046 replica.cpp:712] Persisted action at 0
I1231 21:52:39.706604 31048 replica.cpp:537] Replica received write request for position 0 from (12833)@172.17.0.2:53514
I1231 21:52:39.706676 31048 leveldb.cpp:436] Reading position from leveldb took 32409ns
I1231 21:52:39.729832 31048 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.102756ms
I1231 21:52:39.729871 31048 replica.cpp:712] Persisted action at 0
I1231 21:52:39.730705 31049 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I1231 21:52:39.755010 31049 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.269501ms
I1231 21:52:39.755048 31049 replica.cpp:712] Persisted action at 0
I1231 21:52:39.755070 31049 replica.cpp:697] Replica learned NOP action at position 0
I1231 21:52:39.755797 31043 log.cpp:675] Writer started with ending position 0
I1231 21:52:39.757077 31042 leveldb.cpp:436] Reading position from leveldb took 31085ns
I1231 21:52:39.758257 31053 registrar.cpp:340] Successfully fetched the registry (0B) in 177.724928ms
I1231 21:52:39.758375 31053 registrar.cpp:439] Applied 1 operations in 27957ns; attempting to update the 'registry'
I1231 21:52:39.759246 31048 log.cpp:683] Attempting to append 170 bytes to the log
I1231 21:52:39.759377 31053 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1231 21:52:39.760303 31044 replica.cpp:537] Replica received write request for position 1 from (12834)@172.17.0.2:53514
I1231 21:52:39.786768 31044 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 26.420272ms
I1231 21:52:39.786808 31044 replica.cpp:712] Persisted action at 1
I1231 21:52:39.787547 31049 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I1231 21:52:39.811930 31049 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.343299ms
I1231 21:52:39.811969 31049 replica.cpp:712] Persisted action at 1
I1231 21:52:39.811990 31049 replica.cpp:697] Replica learned APPEND action at position 1
I1231 21:52:39.813053 31043 registrar.cpp:484] Successfully updated the 'registry' in 54.608896ms
I1231 21:52:39.813268 31043 registrar.cpp:370] Successfully recovered registrar
I1231 21:52:39.813382 31055 log.cpp:702] Attempting to truncate the log to 1
I1231 21:52:39.813578 31048 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1231 21:52:39.813797 31047 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I1231 21:52:39.813827 31046 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I1231 21:52:39.814651 31056 replica.cpp:537] Replica received write request for position 2 from (12835)@172.17.0.2:53514
I1231 21:52:39.838635 31056 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 23.942834ms
I1231 21:52:39.838681 31056 replica.cpp:712] Persisted action at 2
I1231 21:52:39.839469 31043 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I1231 21:52:39.863785 31043 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.279224ms
I1231 21:52:39.863865 31043 leveldb.cpp:399] Deleting ~1 keys from leveldb took 40951ns
I1231 21:52:39.863891 31043 replica.cpp:712] Persisted action at 2
I1231 21:52:39.863914 31043 replica.cpp:697] Replica learned TRUNCATE action at position 2
I1231 21:52:39.875010 31022 scheduler.cpp:154] Version: 0.27.0
I1231 21:52:39.875720 31055 scheduler.cpp:236] New master detected at master@172.17.0.2:53514
I1231 21:52:39.876929 31054 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:53514
I1231 21:52:39.878922 31049 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1231 21:52:39.879462 31041 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:44596
I1231 21:52:39.879678 31041 master.cpp:1891] Received subscription request for HTTP framework 'default'
I1231 21:52:39.879745 31041 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1231 21:52:39.880070 31041 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1231 21:52:39.880509 31053 hierarchical.cpp:260] Added framework c9e3aebe-4be7-414a-92de-9bd5b1785f3f-0000
I1231 21:52:39.880563 31041 master.hpp:1659] Sending heartbeat to c9e3aebe-4be7-414a-92de-9bd5b1785f3f-0000
I1231 21:52:39.880587 31053 hierarchical.cpp:1329] No resources available to allocate!
I1231 21:52:39.880635 31053 hierarchical.cpp:1423] No inverse offers to send out!
I1231 21:52:39.880671 31053 hierarchical.cpp:1079] Performed allocation for 0 slaves in 130194ns
I1231 21:52:39.881567 31052 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:53514
I1231 21:52:39.882103 31052 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:53514
I1231 21:52:39.882788 31051 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I1231 21:52:39.882869 31052 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:53514
I1231 21:52:39.884599 31047 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1231 21:52:39.885056 31051 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:44597
I1231 21:52:39.885218 31051 master.cpp:2636] Processing REQUEST call for framework c9e3aebe-4be7-414a-92de-9bd5b1785f3f-0000 (default)
I1231 21:52:39.885402 31046 hierarchical.cpp:579] Received resource request from framework c9e3aebe-4be7-414a-92de-9bd5b1785f3f-0000
I1231 21:52:39.885998 31050 master.cpp:930] Master terminating
I1231 21:52:39.886327 31052 hierarchical.cpp:321] Removed framework c9e3aebe-4be7-414a-92de-9bd5b1785f3f-0000
E1231 21:52:39.887284 31050 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (514 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I1231 21:52:40.015923 31022 leveldb.cpp:174] Opened db in 122.122786ms
I1231 21:52:40.057881 31022 leveldb.cpp:181] Compacted db in 41.916819ms
I1231 21:52:40.057945 31022 leveldb.cpp:196] Created db iterator in 19407ns
I1231 21:52:40.057966 31022 leveldb.cpp:202] Seeked to beginning of db in 1817ns
I1231 21:52:40.057978 31022 leveldb.cpp:271] Iterated through 0 keys in the db in 333ns
I1231 21:52:40.058023 31022 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1231 21:52:40.058513 31048 recover.cpp:447] Starting replica recovery
I1231 21:52:40.058730 31048 recover.cpp:473] Replica is in EMPTY status
I1231 21:52:40.059473 31041 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12843)@172.17.0.2:53514
I1231 21:52:40.059976 31052 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1231 21:52:40.060389 31047 recover.cpp:564] Updating replica status to STARTING
I1231 21:52:40.060982 31055 master.cpp:365] Master 8b128072-f551-4c78-b2d3-057c80268a8e (c39174bc7eb8) started on 172.17.0.2:53514
I1231 21:52:40.061002 31055 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/IFoQxG/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/IFoQxG/master" --zk_session_timeout="10secs"
I1231 21:52:40.061274 31055 master.cpp:414] Master allowing unauthenticated frameworks to register
I1231 21:52:40.061290 31055 master.cpp:417] Master only allowing authenticated slaves to register
I1231 21:52:40.061300 31055 credentials.hpp:35] Loading credentials for authentication from '/tmp/IFoQxG/credentials'
I1231 21:52:40.061507 31055 master.cpp:456] Using default 'crammd5' authenticator
I1231 21:52:40.061615 31055 master.cpp:493] Authorization enabled
I1231 21:52:40.061758 31049 hierarchical.cpp:147] Initialized hierarchical allocator process
I1231 21:52:40.061766 31043 whitelist_watcher.cpp:77] No whitelist given
I1231 21:52:40.063364 31048 master.cpp:1629] The newly elected leader is master@172.17.0.2:53514 with id 8b128072-f551-4c78-b2d3-057c80268a8e
I1231 21:52:40.063397 31048 master.cpp:1642] Elected as the leading master!
I1231 21:52:40.063421 31048 master.cpp:1387] Recovering from registrar
I1231 21:52:40.063558 31041 registrar.cpp:307] Recovering registrar
I1231 21:52:40.106254 31051 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 45.69339ms
I1231 21:52:40.106297 31051 replica.cpp:320] Persisted replica status to STARTING
I1231 21:52:40.106526 31048 recover.cpp:473] Replica is in STARTING status
I1231 21:52:40.107465 31052 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12844)@172.17.0.2:53514
I1231 21:52:40.107800 31045 recover.cpp:193] Received a recover response from a replica in STARTING status
I1231 21:52:40.108155 31044 recover.cpp:564] Updating replica status to VOTING
I1231 21:52:40.149586 31051 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 41.210503ms
I1231 21:52:40.149628 31051 replica.cpp:320] Persisted replica status to VOTING
I1231 21:52:40.149785 31056 recover.cpp:578] Successfully joined the Paxos group
I1231 21:52:40.149999 31056 recover.cpp:462] Recover process terminated
I1231 21:52:40.150544 31046 log.cpp:659] Attempting to start the writer
I1231 21:52:40.151854 31045 replica.cpp:493] Replica received implicit promise request from (12845)@172.17.0.2:53514 with proposal 1
I1231 21:52:40.198171 31045 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 46.271396ms
I1231 21:52:40.198215 31045 replica.cpp:342] Persisted promised to 1
I1231 21:52:40.198845 31050 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1231 21:52:40.200068 31049 replica.cpp:388] Replica received explicit promise request from (12846)@172.17.0.2:53514 for position 0 with proposal 2
I1231 21:52:40.241477 31049 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 41.354145ms
I1231 21:52:40.241516 31049 replica.cpp:712] Persisted action at 0
I1231 21:52:40.242683 31054 replica.cpp:537] Replica received write request for position 0 from (12847)@172.17.0.2:53514
I1231 21:52:40.242734 31054 leveldb.cpp:436] Reading position from leveldb took 23873ns
I1231 21:52:40.283329 31054 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.558477ms
I1231 21:52:40.283368 31054 replica.cpp:712] Persisted action at 0
I1231 21:52:40.284116 31047 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I1231 21:52:40.362895 31047 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 78.660603ms
I1231 21:52:40.362937 31047 replica.cpp:712] Persisted action at 0
I1231 21:52:40.362959 31047 replica.cpp:697] Replica learned NOP action at position 0
I1231 21:52:40.363673 31048 log.cpp:675] Writer started with ending position 0
I1231 21:52:40.364550 31056 leveldb.cpp:436] Reading position from leveldb took 22236ns
I1231 21:52:40.365322 31050 registrar.cpp:340] Successfully fetched the registry (0B) in 301.720064ms
I1231 21:52:40.365417 31050 registrar.cpp:439] Applied 1 operations in 22175ns; attempting to update the 'registry'
I1231 21:52:40.365986 31048 log.cpp:683] Attempting to append 170 bytes to the log
I1231 21:52:40.366098 31046 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1231 21:52:40.366672 31053 replica.cpp:537] Replica received write request for position 1 from (12848)@172.17.0.2:53514
I1231 21:52:40.490187 31053 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 123.461635ms
I1231 21:52:40.490231 31053 replica.cpp:712] Persisted action at 1
I1231 21:52:40.490823 31043 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I1231 21:52:40.523502 31043 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 32.647926ms
I1231 21:52:40.523540 31043 replica.cpp:712] Persisted action at 1
I1231 21:52:40.523564 31043 replica.cpp:697] Replica learned APPEND action at position 1
I1231 21:52:40.524734 31048 registrar.cpp:484] Successfully updated the 'registry' in 159.26016ms
I1231 21:52:40.524883 31048 registrar.cpp:370] Successfully recovered registrar
I1231 21:52:40.525018 31051 log.cpp:702] Attempting to truncate the log to 1
I1231 21:52:40.525293 31042 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1231 21:52:40.525480 31046 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I1231 21:52:40.525507 31049 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I1231 21:52:40.526103 31045 replica.cpp:537] Replica received write request for position 2 from (12849)@172.17.0.2:53514
I1231 21:52:40.548564 31045 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 22.412227ms
I1231 21:52:40.548606 31045 replica.cpp:712] Persisted action at 2
I1231 21:52:40.549343 31050 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I1231 21:52:40.573704 31050 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.316819ms
I1231 21:52:40.573794 31050 leveldb.cpp:399] Deleting ~1 keys from leveldb took 51187ns
I1231 21:52:40.573817 31050 replica.cpp:712] Persisted action at 2
I1231 21:52:40.573840 31050 replica.cpp:697] Replica learned TRUNCATE action at position 2
I1231 21:52:40.576350 31022 scheduler.cpp:154] Version: 0.27.0
I1231 21:52:40.577092 31051 scheduler.cpp:236] New master detected at master@172.17.0.2:53514
I1231 21:52:40.578192 31052 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:53514
I1231 21:52:40.580423 31047 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1231 21:52:40.580977 31051 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:44598
I1231 21:52:40.581382 31051 master.cpp:1891] Received subscription request for HTTP framework 'default'
I1231 21:52:40.581459 31051 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1231 21:52:40.581782 31051 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1231 21:52:40.582207 31043 hierarchical.cpp:260] Added framework 8b128072-f551-4c78-b2d3-057c80268a8e-0000
I1231 21:52:40.582278 31043 hierarchical.cpp:1329] No resources available to allocate!
I1231 21:52:40.582291 31048 master.hpp:1659] Sending heartbeat to 8b128072-f551-4c78-b2d3-057c80268a8e-0000
I1231 21:52:40.582423 31043 hierarchical.cpp:1423] No inverse offers to send out!
I1231 21:52:40.582463 31043 hierarchical.cpp:1079] Performed allocation for 0 slaves in 219941ns
I1231 21:52:40.583564 31041 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:53514
I1231 21:52:40.584029 31041 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:53514
I1231 21:52:40.584708 31047 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I1231 21:52:40.584763 31041 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:53514
I1231 21:52:40.586623 31053 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1231 21:52:40.587070 31043 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:44599
I1231 21:52:40.587352 31043 master.cpp:2636] Processing REQUEST call for framework 8b128072-f551-4c78-b2d3-057c80268a8e-0000 (default)
I1231 21:52:40.587539 31052 hierarchical.cpp:579] Received resource request from framework 8b128072-f551-4c78-b2d3-057c80268a8e-0000
I1231 21:52:40.587937 31050 master.cpp:930] Master terminating
I1231 21:52:40.588250 31052 hierarchical.cpp:321] Removed framework 8b128072-f551-4c78-b2d3-057c80268a8e-0000
E1231 21:52:40.590493 31050 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (702 ms)
[----------] 22 tests from ContentType/SchedulerTest (16024 ms total)
[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (722853 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-1451596350-28453
Untagged: mesos-1451596350-28453:latest
Deleted: d56e42d0b074bfa7a9722661168cb27ea5b067f7568f9d7d223857643256bd3f
Deleted: a2f1634767a1e2ffc05388024836c9d335903b9070fd33c6e9d9ae5f8beb8406
Deleted: 3abb288d97a97bf7ef88067d77a024a3ea389fa171796ac2514763c49a89b8e8
Deleted: 31b395f29e85832b84612ebcbb1be4481365ceb54214940bd9f52f6e7f441cc4
Deleted: 419f1e69b1cb9a1bf4e670ba2bdf69974102668e48498ca32beb05ba61e81966
Deleted: ac8f3ad94ccc7b6c4d218b958a6c3cf5ff067c7bf34ff84ff39c6bd44795436a
Deleted: fe8789a1a38c61c9deae6cd4454de8a9a41820289a8406397f44abb7eb49b77f
Deleted: 36df687a1e5518985b56d62a3c6a48263996a2b6e2b41aab8696e77aa0073a2d
Deleted: 3d22cd2341b6097e41c235409f5128567bd1f286513800c853640370f8be5e7d
Deleted: c108c5b915eca2c52bc6db66f656f30257a015bda3a933d1edea92f64ed0bfb7
Deleted: a16e198df9eca2c7f77767d1c43b8fafd1422e917a9f08f54915bf8954a52efb
Deleted: a9b0b489432cb938c66e73224111fb688b98c87fe1a659cdc6a27d266c583174
Deleted: 93565ff02d594090a61b19cd94c545e1d22fdc0bd5754da5c8a3ff02b630256e
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