You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2016/01/11 22:13:36 UTC
Build failed in Jenkins: mesos-reviewbot #10722
See <https://builds.apache.org/job/mesos-reviewbot/10722/>
------------------------------------------
[...truncated 163320 lines...]
I0111 21:13:24.598057 21093 leveldb.cpp:174] Opened db in 3.123524ms
I0111 21:13:24.599180 21093 leveldb.cpp:181] Compacted db in 1.088028ms
I0111 21:13:24.599234 21093 leveldb.cpp:196] Created db iterator in 21598ns
I0111 21:13:24.599252 21093 leveldb.cpp:202] Seeked to beginning of db in 1832ns
I0111 21:13:24.599261 21093 leveldb.cpp:271] Iterated through 0 keys in the db in 260ns
I0111 21:13:24.599310 21093 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0111 21:13:24.599989 21119 recover.cpp:447] Starting replica recovery
I0111 21:13:24.600421 21119 recover.cpp:473] Replica is in EMPTY status
I0111 21:13:24.601584 21122 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13437)@172.17.0.1:53056
I0111 21:13:24.602025 21123 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0111 21:13:24.602491 21118 recover.cpp:564] Updating replica status to STARTING
I0111 21:13:24.603031 21117 master.cpp:372] Master ae1ef4a9-3015-4f20-8693-411672395003 (46c2945f3b41) started on 172.17.0.1:53056
I0111 21:13:24.603283 21113 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 575616ns
I0111 21:13:24.603309 21113 replica.cpp:320] Persisted replica status to STARTING
I0111 21:13:24.603057 21117 master.cpp:374] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/E8WaZJ/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_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/E8WaZJ/master" --zk_session_timeout="10secs"
I0111 21:13:24.603404 21117 master.cpp:421] Master allowing unauthenticated frameworks to register
I0111 21:13:24.603420 21117 master.cpp:424] Master only allowing authenticated slaves to register
I0111 21:13:24.603431 21117 credentials.hpp:35] Loading credentials for authentication from '/tmp/E8WaZJ/credentials'
I0111 21:13:24.603503 21118 recover.cpp:473] Replica is in STARTING status
I0111 21:13:24.603797 21117 master.cpp:464] Using default 'crammd5' authenticator
I0111 21:13:24.603940 21117 master.cpp:533] Using default 'basic' HTTP authenticator
I0111 21:13:24.604084 21117 master.cpp:567] Authorization enabled
I0111 21:13:24.604254 21115 hierarchical.cpp:147] Initialized hierarchical allocator process
I0111 21:13:24.604264 21127 whitelist_watcher.cpp:77] No whitelist given
I0111 21:13:24.604509 21122 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13439)@172.17.0.1:53056
I0111 21:13:24.605026 21121 recover.cpp:193] Received a recover response from a replica in STARTING status
I0111 21:13:24.605509 21116 recover.cpp:564] Updating replica status to VOTING
I0111 21:13:24.606019 21126 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 337589ns
I0111 21:13:24.606042 21126 replica.cpp:320] Persisted replica status to VOTING
I0111 21:13:24.606184 21117 recover.cpp:578] Successfully joined the Paxos group
I0111 21:13:24.606420 21126 master.cpp:1715] The newly elected leader is master@172.17.0.1:53056 with id ae1ef4a9-3015-4f20-8693-411672395003
I0111 21:13:24.606451 21126 master.cpp:1728] Elected as the leading master!
I0111 21:13:24.606477 21126 master.cpp:1473] Recovering from registrar
I0111 21:13:24.606581 21117 recover.cpp:462] Recover process terminated
I0111 21:13:24.606653 21114 registrar.cpp:307] Recovering registrar
I0111 21:13:24.607405 21124 log.cpp:659] Attempting to start the writer
I0111 21:13:24.608558 21118 replica.cpp:493] Replica received implicit promise request from (13440)@172.17.0.1:53056 with proposal 1
I0111 21:13:24.608891 21118 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 302766ns
I0111 21:13:24.608914 21118 replica.cpp:342] Persisted promised to 1
I0111 21:13:24.609402 21125 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0111 21:13:24.610472 21117 replica.cpp:388] Replica received explicit promise request from (13441)@172.17.0.1:53056 for position 0 with proposal 2
I0111 21:13:24.610872 21117 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 363197ns
I0111 21:13:24.610899 21117 replica.cpp:712] Persisted action at 0
I0111 21:13:24.611891 21119 replica.cpp:537] Replica received write request for position 0 from (13442)@172.17.0.1:53056
I0111 21:13:24.611953 21119 leveldb.cpp:436] Reading position from leveldb took 33082ns
I0111 21:13:24.612289 21119 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 287348ns
I0111 21:13:24.612313 21119 replica.cpp:712] Persisted action at 0
I0111 21:13:24.612876 21126 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0111 21:13:24.613366 21126 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 456057ns
I0111 21:13:24.613389 21126 replica.cpp:712] Persisted action at 0
I0111 21:13:24.613404 21126 replica.cpp:697] Replica learned NOP action at position 0
I0111 21:13:24.613858 21117 log.cpp:675] Writer started with ending position 0
I0111 21:13:24.614835 21126 leveldb.cpp:436] Reading position from leveldb took 23973ns
I0111 21:13:24.615666 21125 registrar.cpp:340] Successfully fetched the registry (0B) in 8.915712ms
I0111 21:13:24.615777 21125 registrar.cpp:439] Applied 1 operations in 29115ns; attempting to update the 'registry'
I0111 21:13:24.616451 21119 log.cpp:683] Attempting to append 170 bytes to the log
I0111 21:13:24.616652 21115 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0111 21:13:24.617282 21113 replica.cpp:537] Replica received write request for position 1 from (13443)@172.17.0.1:53056
I0111 21:13:24.617769 21113 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 446993ns
I0111 21:13:24.617792 21113 replica.cpp:712] Persisted action at 1
I0111 21:13:24.618338 21124 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0111 21:13:24.618782 21124 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 414507ns
I0111 21:13:24.618805 21124 replica.cpp:712] Persisted action at 1
I0111 21:13:24.618820 21124 replica.cpp:697] Replica learned APPEND action at position 1
I0111 21:13:24.619709 21116 registrar.cpp:484] Successfully updated the 'registry' in 3.873024ms
I0111 21:13:24.619839 21116 registrar.cpp:370] Successfully recovered registrar
I0111 21:13:24.619912 21124 log.cpp:702] Attempting to truncate the log to 1
I0111 21:13:24.620025 21127 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0111 21:13:24.620352 21116 master.cpp:1525] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0111 21:13:24.620388 21115 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0111 21:13:24.620875 21113 replica.cpp:537] Replica received write request for position 2 from (13444)@172.17.0.1:53056
I0111 21:13:24.621285 21113 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 373081ns
I0111 21:13:24.621309 21113 replica.cpp:712] Persisted action at 2
I0111 21:13:24.621888 21124 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0111 21:13:24.622256 21124 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 338483ns
I0111 21:13:24.622303 21124 leveldb.cpp:399] Deleting ~1 keys from leveldb took 24706ns
I0111 21:13:24.622324 21124 replica.cpp:712] Persisted action at 2
I0111 21:13:24.622350 21124 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0111 21:13:24.631100 21093 scheduler.cpp:154] Version: 0.27.0
I0111 21:13:24.631737 21116 scheduler.cpp:236] New master detected at master@172.17.0.1:53056
I0111 21:13:24.633062 21114 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.1:53056
I0111 21:13:24.634886 21121 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0111 21:13:24.635391 21120 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:41873
I0111 21:13:24.635593 21120 master.cpp:1977] Received subscription request for HTTP framework 'default'
I0111 21:13:24.635675 21120 master.cpp:1754] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0111 21:13:24.635956 21120 master.cpp:2068] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0111 21:13:24.636423 21126 hierarchical.cpp:260] Added framework ae1ef4a9-3015-4f20-8693-411672395003-0000
I0111 21:13:24.636487 21126 hierarchical.cpp:1329] No resources available to allocate!
I0111 21:13:24.636521 21126 hierarchical.cpp:1423] No inverse offers to send out!
I0111 21:13:24.636548 21126 hierarchical.cpp:1079] Performed allocation for 0 slaves in 94632ns
I0111 21:13:24.636580 21126 master.hpp:1657] Sending heartbeat to ae1ef4a9-3015-4f20-8693-411672395003-0000
I0111 21:13:24.637887 21113 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.1:53056
I0111 21:13:24.638345 21113 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.1:53056
I0111 21:13:24.638847 21116 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0111 21:13:24.639020 21112 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.1:53056
I0111 21:13:24.640566 21125 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0111 21:13:24.641001 21119 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:41874
I0111 21:13:24.641109 21119 master.cpp:2722] Processing REQUEST call for framework ae1ef4a9-3015-4f20-8693-411672395003-0000 (default)
I0111 21:13:24.641276 21114 hierarchical.cpp:579] Received resource request from framework ae1ef4a9-3015-4f20-8693-411672395003-0000
I0111 21:13:24.642690 21113 master.cpp:1016] Master terminating
I0111 21:13:24.642931 21125 hierarchical.cpp:321] Removed framework ae1ef4a9-3015-4f20-8693-411672395003-0000
E0111 21:13:24.643695 21112 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (55 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0111 21:13:24.653571 21093 leveldb.cpp:174] Opened db in 3.181065ms
I0111 21:13:24.654914 21093 leveldb.cpp:181] Compacted db in 1.29079ms
I0111 21:13:24.655007 21093 leveldb.cpp:196] Created db iterator in 25031ns
I0111 21:13:24.655024 21093 leveldb.cpp:202] Seeked to beginning of db in 2055ns
I0111 21:13:24.655031 21093 leveldb.cpp:271] Iterated through 0 keys in the db in 236ns
I0111 21:13:24.655083 21093 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0111 21:13:24.655750 21116 recover.cpp:447] Starting replica recovery
I0111 21:13:24.656288 21116 recover.cpp:473] Replica is in EMPTY status
I0111 21:13:24.657593 21117 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13452)@172.17.0.1:53056
I0111 21:13:24.657940 21120 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0111 21:13:24.658608 21118 recover.cpp:564] Updating replica status to STARTING
I0111 21:13:24.659009 21122 master.cpp:372] Master 1fd21ea2-a4c2-49af-bb11-bf1a0d296131 (46c2945f3b41) started on 172.17.0.1:53056
I0111 21:13:24.659039 21122 master.cpp:374] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/33L5Qy/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_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/33L5Qy/master" --zk_session_timeout="10secs"
I0111 21:13:24.659342 21122 master.cpp:421] Master allowing unauthenticated frameworks to register
I0111 21:13:24.659354 21122 master.cpp:424] Master only allowing authenticated slaves to register
I0111 21:13:24.659363 21122 credentials.hpp:35] Loading credentials for authentication from '/tmp/33L5Qy/credentials'
I0111 21:13:24.659683 21125 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 566257ns
I0111 21:13:24.659696 21122 master.cpp:464] Using default 'crammd5' authenticator
I0111 21:13:24.659721 21125 replica.cpp:320] Persisted replica status to STARTING
I0111 21:13:24.659832 21122 master.cpp:533] Using default 'basic' HTTP authenticator
I0111 21:13:24.659965 21122 master.cpp:567] Authorization enabled
I0111 21:13:24.660055 21119 recover.cpp:473] Replica is in STARTING status
I0111 21:13:24.660171 21121 hierarchical.cpp:147] Initialized hierarchical allocator process
I0111 21:13:24.660200 21127 whitelist_watcher.cpp:77] No whitelist given
I0111 21:13:24.661299 21124 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13454)@172.17.0.1:53056
I0111 21:13:24.661756 21119 recover.cpp:193] Received a recover response from a replica in STARTING status
I0111 21:13:24.662384 21121 recover.cpp:564] Updating replica status to VOTING
I0111 21:13:24.663059 21124 master.cpp:1715] The newly elected leader is master@172.17.0.1:53056 with id 1fd21ea2-a4c2-49af-bb11-bf1a0d296131
I0111 21:13:24.663099 21124 master.cpp:1728] Elected as the leading master!
I0111 21:13:24.663125 21124 master.cpp:1473] Recovering from registrar
I0111 21:13:24.663333 21118 registrar.cpp:307] Recovering registrar
I0111 21:13:24.663363 21126 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 459095ns
I0111 21:13:24.663396 21126 replica.cpp:320] Persisted replica status to VOTING
I0111 21:13:24.663677 21122 recover.cpp:578] Successfully joined the Paxos group
I0111 21:13:24.664119 21122 recover.cpp:462] Recover process terminated
I0111 21:13:24.664757 21112 log.cpp:659] Attempting to start the writer
I0111 21:13:24.666337 21125 replica.cpp:493] Replica received implicit promise request from (13455)@172.17.0.1:53056 with proposal 1
I0111 21:13:24.666812 21125 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 436648ns
I0111 21:13:24.666842 21125 replica.cpp:342] Persisted promised to 1
I0111 21:13:24.667531 21114 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0111 21:13:24.668941 21119 replica.cpp:388] Replica received explicit promise request from (13456)@172.17.0.1:53056 for position 0 with proposal 2
I0111 21:13:24.669345 21119 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 353706ns
I0111 21:13:24.669375 21119 replica.cpp:712] Persisted action at 0
I0111 21:13:24.670542 21127 replica.cpp:537] Replica received write request for position 0 from (13457)@172.17.0.1:53056
I0111 21:13:24.670672 21127 leveldb.cpp:436] Reading position from leveldb took 78252ns
I0111 21:13:24.671083 21127 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 362020ns
I0111 21:13:24.671108 21127 replica.cpp:712] Persisted action at 0
I0111 21:13:24.671665 21119 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0111 21:13:24.672009 21119 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 310906ns
I0111 21:13:24.672032 21119 replica.cpp:712] Persisted action at 0
I0111 21:13:24.672050 21119 replica.cpp:697] Replica learned NOP action at position 0
I0111 21:13:24.672569 21112 log.cpp:675] Writer started with ending position 0
I0111 21:13:24.673673 21117 leveldb.cpp:436] Reading position from leveldb took 26132ns
I0111 21:13:24.674633 21117 registrar.cpp:340] Successfully fetched the registry (0B) in 11.236864ms
I0111 21:13:24.674774 21117 registrar.cpp:439] Applied 1 operations in 39295ns; attempting to update the 'registry'
I0111 21:13:24.675475 21114 log.cpp:683] Attempting to append 170 bytes to the log
I0111 21:13:24.675604 21125 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0111 21:13:24.676230 21114 replica.cpp:537] Replica received write request for position 1 from (13458)@172.17.0.1:53056
I0111 21:13:24.676666 21114 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 394306ns
I0111 21:13:24.676688 21114 replica.cpp:712] Persisted action at 1
I0111 21:13:24.677428 21120 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0111 21:13:24.677837 21120 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 378983ns
I0111 21:13:24.677860 21120 replica.cpp:712] Persisted action at 1
I0111 21:13:24.677875 21120 replica.cpp:697] Replica learned APPEND action at position 1
I0111 21:13:24.678738 21120 registrar.cpp:484] Successfully updated the 'registry' in 3.905024ms
I0111 21:13:24.678863 21120 registrar.cpp:370] Successfully recovered registrar
I0111 21:13:24.678989 21119 log.cpp:702] Attempting to truncate the log to 1
I0111 21:13:24.679155 21123 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0111 21:13:24.679266 21113 master.cpp:1525] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0111 21:13:24.679296 21118 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0111 21:13:24.679966 21124 replica.cpp:537] Replica received write request for position 2 from (13459)@172.17.0.1:53056
I0111 21:13:24.680318 21124 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 315407ns
I0111 21:13:24.680344 21124 replica.cpp:712] Persisted action at 2
I0111 21:13:24.681066 21120 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0111 21:13:24.681426 21120 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 332384ns
I0111 21:13:24.681473 21120 leveldb.cpp:399] Deleting ~1 keys from leveldb took 24945ns
I0111 21:13:24.681498 21120 replica.cpp:712] Persisted action at 2
I0111 21:13:24.681517 21120 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0111 21:13:24.690217 21093 scheduler.cpp:154] Version: 0.27.0
I0111 21:13:24.691099 21120 scheduler.cpp:236] New master detected at master@172.17.0.1:53056
I0111 21:13:24.692121 21122 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.1:53056
I0111 21:13:24.694396 21124 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0111 21:13:24.695078 21113 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:41875
I0111 21:13:24.695430 21113 master.cpp:1977] Received subscription request for HTTP framework 'default'
I0111 21:13:24.695510 21113 master.cpp:1754] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0111 21:13:24.696070 21127 master.cpp:2068] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0111 21:13:24.696509 21114 hierarchical.cpp:260] Added framework 1fd21ea2-a4c2-49af-bb11-bf1a0d296131-0000
I0111 21:13:24.696588 21113 master.hpp:1657] Sending heartbeat to 1fd21ea2-a4c2-49af-bb11-bf1a0d296131-0000
I0111 21:13:24.696691 21114 hierarchical.cpp:1329] No resources available to allocate!
I0111 21:13:24.697018 21114 hierarchical.cpp:1423] No inverse offers to send out!
I0111 21:13:24.697046 21114 hierarchical.cpp:1079] Performed allocation for 0 slaves in 395384ns
I0111 21:13:24.697595 21121 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.1:53056
I0111 21:13:24.698271 21121 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.1:53056
I0111 21:13:24.699107 21121 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.1:53056
I0111 21:13:24.699136 21123 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0111 21:13:24.700873 21127 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0111 21:13:24.701213 21126 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:41876
I0111 21:13:24.701462 21126 master.cpp:2722] Processing REQUEST call for framework 1fd21ea2-a4c2-49af-bb11-bf1a0d296131-0000 (default)
I0111 21:13:24.701596 21118 hierarchical.cpp:579] Received resource request from framework 1fd21ea2-a4c2-49af-bb11-bf1a0d296131-0000
I0111 21:13:24.702008 21124 master.cpp:1016] Master terminating
I0111 21:13:24.702356 21115 hierarchical.cpp:321] Removed framework 1fd21ea2-a4c2-49af-bb11-bf1a0d296131-0000
E0111 21:13:24.703461 21123 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (60 ms)
[----------] 22 tests from ContentType/SchedulerTest (4088 ms total)
[----------] Global test environment tear-down
[==========] 925 tests from 122 test cases ran. (365490 ms total)
[ PASSED ] 924 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] PersistentVolumeTest.BadACLNoPrincipal
1 FAILED TEST
YOU HAVE 7 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1452545028-8938
Untagged: mesos-1452545028-8938:latest
Deleted: 647ecaf0223dc6c05d7cc15574a14c63e100b0f3c229464b46e7630cacda68ce
Deleted: dfc25c1635ee84e321d42dafa4bed167d3101262d056b392a2b6964c33ac334e
Deleted: b3802a26a55f8a23313d54b21d2bcdbd72703deb5d76c8509c0f8b9a206bbe96
Deleted: 3e7225ac44a13787703916ab71832c60ab3000cbd8a483a3fa714076f37cffd0
Deleted: b0e0662ce453b54a9de8952bbe490f6db22d027cd2dbfc92217f5c86880b0a2c
Deleted: dec354fe28822d2a431e11c62367326f0b50d4e025cb0193db21dde6fc1c7978
Deleted: 4f8a35a584a652dd1049b3b9b1517cadab7b2a20c0ca2697c0be29533a54fdda
Deleted: f76e65f8a66d5b65a18f3d5689ac9bffdcad3cd7caabfebeef9ee19983d9fada
Deleted: 1cf1179013058e13821735d4d705e5d2ab5adf05e610a1522c050a6678916076
Deleted: 33a237ebe24d1797ef10c9f376f9d58f7737d921812331ae89fc13e308ad534c
Deleted: cc7b14a07c6bf6e13325d486e0baa1598f2a7b4dc3bf3f578e0593c3938fc3bb
Deleted: 505a6919802646e35ba97552b6de7ca682f02f0c3228456658dfda989c2f428a
Deleted: df651c56bc922daf12cec8737942a88ad70efd84568e5a708088f89d1547978e
Deleted: 617af709fd6efa541c1d67f717347b9926b4601284796d30562e2af780af4378
Error handling URL https://reviews.apache.org/api/review-requests/41871/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard 521dbb6c91affddf3ed6dc1e00c885215e5a7343
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : mesos-reviewbot #10725
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10725/changes>
Build failed in Jenkins: mesos-reviewbot #10724
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10724/>
------------------------------------------
[...truncated 169386 lines...]
I0111 23:57:31.268055 31415 leveldb.cpp:181] Compacted db in 59.082424ms
I0111 23:57:31.268165 31415 leveldb.cpp:196] Created db iterator in 31562ns
I0111 23:57:31.268189 31415 leveldb.cpp:202] Seeked to beginning of db in 4131ns
I0111 23:57:31.268204 31415 leveldb.cpp:271] Iterated through 0 keys in the db in 555ns
I0111 23:57:31.268271 31415 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0111 23:57:31.270128 31449 recover.cpp:447] Starting replica recovery
I0111 23:57:31.270591 31449 recover.cpp:473] Replica is in EMPTY status
I0111 23:57:31.272598 31446 master.cpp:372] Master 50a34537-0691-4aa9-92b4-785351507aee (de632bf68a90) started on 172.17.0.3:59578
I0111 23:57:31.272625 31446 master.cpp:374] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/GJWjh4/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_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/GJWjh4/master" --zk_session_timeout="10secs"
I0111 23:57:31.272948 31446 master.cpp:421] Master allowing unauthenticated frameworks to register
I0111 23:57:31.272958 31446 master.cpp:424] Master only allowing authenticated slaves to register
I0111 23:57:31.272975 31446 credentials.hpp:35] Loading credentials for authentication from '/tmp/GJWjh4/credentials'
I0111 23:57:31.273330 31446 master.cpp:464] Using default 'crammd5' authenticator
I0111 23:57:31.273483 31446 master.cpp:533] Using default 'basic' HTTP authenticator
I0111 23:57:31.273632 31446 master.cpp:567] Authorization enabled
I0111 23:57:31.273821 31443 hierarchical.cpp:147] Initialized hierarchical allocator process
I0111 23:57:31.273882 31443 whitelist_watcher.cpp:77] No whitelist given
I0111 23:57:31.274435 31443 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13462)@172.17.0.3:59578
I0111 23:57:31.274813 31436 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0111 23:57:31.275440 31449 recover.cpp:564] Updating replica status to STARTING
I0111 23:57:31.277655 31442 master.cpp:1715] The newly elected leader is master@172.17.0.3:59578 with id 50a34537-0691-4aa9-92b4-785351507aee
I0111 23:57:31.277690 31442 master.cpp:1728] Elected as the leading master!
I0111 23:57:31.277709 31442 master.cpp:1473] Recovering from registrar
I0111 23:57:31.277842 31438 registrar.cpp:307] Recovering registrar
I0111 23:57:31.322109 31434 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 46.318514ms
I0111 23:57:31.322274 31434 replica.cpp:320] Persisted replica status to STARTING
I0111 23:57:31.322826 31442 recover.cpp:473] Replica is in STARTING status
I0111 23:57:31.324084 31448 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13463)@172.17.0.3:59578
I0111 23:57:31.324504 31436 recover.cpp:193] Received a recover response from a replica in STARTING status
I0111 23:57:31.324957 31440 recover.cpp:564] Updating replica status to VOTING
I0111 23:57:31.364115 31442 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 38.998715ms
I0111 23:57:31.364208 31442 replica.cpp:320] Persisted replica status to VOTING
I0111 23:57:31.364404 31443 recover.cpp:578] Successfully joined the Paxos group
I0111 23:57:31.364666 31443 recover.cpp:462] Recover process terminated
I0111 23:57:31.365309 31448 log.cpp:659] Attempting to start the writer
I0111 23:57:31.366699 31434 replica.cpp:493] Replica received implicit promise request from (13464)@172.17.0.3:59578 with proposal 1
I0111 23:57:31.406275 31434 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.515965ms
I0111 23:57:31.406369 31434 replica.cpp:342] Persisted promised to 1
I0111 23:57:31.407858 31448 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0111 23:57:31.409754 31439 replica.cpp:388] Replica received explicit promise request from (13465)@172.17.0.3:59578 for position 0 with proposal 2
I0111 23:57:31.444000 31439 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 34.162405ms
I0111 23:57:31.444097 31439 replica.cpp:712] Persisted action at 0
I0111 23:57:31.446231 31449 replica.cpp:537] Replica received write request for position 0 from (13466)@172.17.0.3:59578
I0111 23:57:31.446374 31449 leveldb.cpp:436] Reading position from leveldb took 66355ns
I0111 23:57:31.516057 31449 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 69.595499ms
I0111 23:57:31.516156 31449 replica.cpp:712] Persisted action at 0
I0111 23:57:31.517066 31435 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0111 23:57:31.593533 31435 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 76.393697ms
I0111 23:57:31.593644 31435 replica.cpp:712] Persisted action at 0
I0111 23:57:31.593693 31435 replica.cpp:697] Replica learned NOP action at position 0
I0111 23:57:31.595118 31436 log.cpp:675] Writer started with ending position 0
I0111 23:57:31.596896 31436 leveldb.cpp:436] Reading position from leveldb took 67422ns
I0111 23:57:31.598198 31435 registrar.cpp:340] Successfully fetched the registry (0B) in 320.306944ms
I0111 23:57:31.598371 31435 registrar.cpp:439] Applied 1 operations in 47433ns; attempting to update the 'registry'
I0111 23:57:31.599302 31443 log.cpp:683] Attempting to append 170 bytes to the log
I0111 23:57:31.599454 31435 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0111 23:57:31.600581 31435 replica.cpp:537] Replica received write request for position 1 from (13467)@172.17.0.3:59578
I0111 23:57:31.644083 31435 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 43.425036ms
I0111 23:57:31.644201 31435 replica.cpp:712] Persisted action at 1
I0111 23:57:31.646165 31446 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0111 23:57:31.677677 31446 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 31.413145ms
I0111 23:57:31.677774 31446 replica.cpp:712] Persisted action at 1
I0111 23:57:31.677813 31446 replica.cpp:697] Replica learned APPEND action at position 1
I0111 23:57:31.680173 31446 registrar.cpp:484] Successfully updated the 'registry' in 81.71392ms
I0111 23:57:31.680361 31446 registrar.cpp:370] Successfully recovered registrar
I0111 23:57:31.680666 31446 log.cpp:702] Attempting to truncate the log to 1
I0111 23:57:31.681357 31442 master.cpp:1525] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0111 23:57:31.681505 31438 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0111 23:57:31.683396 31438 replica.cpp:537] Replica received write request for position 2 from (13468)@172.17.0.3:59578
I0111 23:57:31.681718 31436 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0111 23:57:31.727610 31438 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 44.037331ms
I0111 23:57:31.727696 31438 replica.cpp:712] Persisted action at 2
I0111 23:57:31.729027 31436 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0111 23:57:31.861794 31436 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 132.706399ms
I0111 23:57:31.862015 31436 leveldb.cpp:399] Deleting ~1 keys from leveldb took 119754ns
I0111 23:57:31.862053 31436 replica.cpp:712] Persisted action at 2
I0111 23:57:31.862103 31436 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0111 23:57:31.864051 31415 scheduler.cpp:154] Version: 0.27.0
I0111 23:57:31.864832 31449 scheduler.cpp:236] New master detected at master@172.17.0.3:59578
I0111 23:57:31.866596 31442 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.3:59578
I0111 23:57:31.869094 31444 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0111 23:57:31.869791 31443 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:51952
I0111 23:57:31.870117 31443 master.cpp:1977] Received subscription request for HTTP framework 'default'
I0111 23:57:31.870201 31443 master.cpp:1754] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0111 23:57:31.870564 31443 master.cpp:2068] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0111 23:57:31.871120 31444 hierarchical.cpp:260] Added framework 50a34537-0691-4aa9-92b4-785351507aee-0000
I0111 23:57:31.871199 31444 hierarchical.cpp:1329] No resources available to allocate!
I0111 23:57:31.871233 31444 hierarchical.cpp:1423] No inverse offers to send out!
I0111 23:57:31.871259 31444 hierarchical.cpp:1079] Performed allocation for 0 slaves in 113596ns
I0111 23:57:31.871292 31443 master.hpp:1657] Sending heartbeat to 50a34537-0691-4aa9-92b4-785351507aee-0000
I0111 23:57:31.873736 31444 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.3:59578
I0111 23:57:31.874665 31444 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.3:59578
I0111 23:57:31.875310 31444 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0111 23:57:31.876008 31434 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.3:59578
I0111 23:57:31.879087 31449 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0111 23:57:31.879565 31443 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:51953
I0111 23:57:31.879724 31443 master.cpp:2722] Processing REQUEST call for framework 50a34537-0691-4aa9-92b4-785351507aee-0000 (default)
I0111 23:57:31.879987 31443 hierarchical.cpp:579] Received resource request from framework 50a34537-0691-4aa9-92b4-785351507aee-0000
I0111 23:57:31.880626 31415 master.cpp:1016] Master terminating
I0111 23:57:31.881311 31439 hierarchical.cpp:321] Removed framework 50a34537-0691-4aa9-92b4-785351507aee-0000
E0111 23:57:31.883000 31440 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (854 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0111 23:57:32.097318 31415 leveldb.cpp:174] Opened db in 197.715977ms
I0111 23:57:32.138262 31415 leveldb.cpp:181] Compacted db in 40.853809ms
I0111 23:57:32.138366 31415 leveldb.cpp:196] Created db iterator in 28822ns
I0111 23:57:32.138388 31415 leveldb.cpp:202] Seeked to beginning of db in 4086ns
I0111 23:57:32.138399 31415 leveldb.cpp:271] Iterated through 0 keys in the db in 265ns
I0111 23:57:32.138461 31415 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0111 23:57:32.142372 31448 master.cpp:372] Master ecb54e3e-dd13-4727-8e1b-18af47e6f312 (de632bf68a90) started on 172.17.0.3:59578
I0111 23:57:32.142535 31444 recover.cpp:447] Starting replica recovery
I0111 23:57:32.142416 31448 master.cpp:374] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/zxnYgc/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_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/zxnYgc/master" --zk_session_timeout="10secs"
I0111 23:57:32.142776 31448 master.cpp:421] Master allowing unauthenticated frameworks to register
I0111 23:57:32.142791 31448 master.cpp:424] Master only allowing authenticated slaves to register
I0111 23:57:32.142801 31448 credentials.hpp:35] Loading credentials for authentication from '/tmp/zxnYgc/credentials'
I0111 23:57:32.143039 31444 recover.cpp:473] Replica is in EMPTY status
I0111 23:57:32.143200 31448 master.cpp:464] Using default 'crammd5' authenticator
I0111 23:57:32.143353 31448 master.cpp:533] Using default 'basic' HTTP authenticator
I0111 23:57:32.143481 31448 master.cpp:567] Authorization enabled
I0111 23:57:32.143867 31443 hierarchical.cpp:147] Initialized hierarchical allocator process
I0111 23:57:32.143930 31443 whitelist_watcher.cpp:77] No whitelist given
I0111 23:57:32.148901 31444 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13477)@172.17.0.3:59578
I0111 23:57:32.149462 31444 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0111 23:57:32.150210 31444 recover.cpp:564] Updating replica status to STARTING
I0111 23:57:32.152340 31448 master.cpp:1715] The newly elected leader is master@172.17.0.3:59578 with id ecb54e3e-dd13-4727-8e1b-18af47e6f312
I0111 23:57:32.152488 31448 master.cpp:1728] Elected as the leading master!
I0111 23:57:32.152622 31448 master.cpp:1473] Recovering from registrar
I0111 23:57:32.152917 31439 registrar.cpp:307] Recovering registrar
I0111 23:57:32.196841 31444 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 46.34419ms
I0111 23:57:32.196919 31444 replica.cpp:320] Persisted replica status to STARTING
I0111 23:57:32.197242 31439 recover.cpp:473] Replica is in STARTING status
I0111 23:57:32.198901 31437 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13478)@172.17.0.3:59578
I0111 23:57:32.199594 31447 recover.cpp:193] Received a recover response from a replica in STARTING status
I0111 23:57:32.200202 31438 recover.cpp:564] Updating replica status to VOTING
I0111 23:57:32.251889 31443 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 51.469531ms
I0111 23:57:32.251986 31443 replica.cpp:320] Persisted replica status to VOTING
I0111 23:57:32.252230 31436 recover.cpp:578] Successfully joined the Paxos group
I0111 23:57:32.252437 31436 recover.cpp:462] Recover process terminated
I0111 23:57:32.253053 31437 log.cpp:659] Attempting to start the writer
I0111 23:57:32.254402 31437 replica.cpp:493] Replica received implicit promise request from (13479)@172.17.0.3:59578 with proposal 1
I0111 23:57:32.302081 31437 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 47.619514ms
I0111 23:57:32.302186 31437 replica.cpp:342] Persisted promised to 1
I0111 23:57:32.303134 31448 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0111 23:57:32.304446 31440 replica.cpp:388] Replica received explicit promise request from (13480)@172.17.0.3:59578 for position 0 with proposal 2
I0111 23:57:32.347756 31440 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 43.236715ms
I0111 23:57:32.347852 31440 replica.cpp:712] Persisted action at 0
I0111 23:57:32.349283 31434 replica.cpp:537] Replica received write request for position 0 from (13481)@172.17.0.3:59578
I0111 23:57:32.349373 31434 leveldb.cpp:436] Reading position from leveldb took 45869ns
I0111 23:57:32.388906 31434 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 39.465084ms
I0111 23:57:32.389009 31434 replica.cpp:712] Persisted action at 0
I0111 23:57:32.389852 31443 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0111 23:57:32.422713 31443 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 32.807554ms
I0111 23:57:32.422788 31443 replica.cpp:712] Persisted action at 0
I0111 23:57:32.422832 31443 replica.cpp:697] Replica learned NOP action at position 0
I0111 23:57:32.423959 31443 log.cpp:675] Writer started with ending position 0
I0111 23:57:32.425544 31440 leveldb.cpp:436] Reading position from leveldb took 72994ns
I0111 23:57:32.426764 31440 registrar.cpp:340] Successfully fetched the registry (0B) in 273.769984ms
I0111 23:57:32.426906 31440 registrar.cpp:439] Applied 1 operations in 39817ns; attempting to update the 'registry'
I0111 23:57:32.427783 31442 log.cpp:683] Attempting to append 170 bytes to the log
I0111 23:57:32.427956 31446 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0111 23:57:32.428796 31434 replica.cpp:537] Replica received write request for position 1 from (13482)@172.17.0.3:59578
I0111 23:57:32.447782 31434 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 18.922858ms
I0111 23:57:32.447883 31434 replica.cpp:712] Persisted action at 1
I0111 23:57:32.449525 31435 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0111 23:57:32.495712 31435 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 46.116979ms
I0111 23:57:32.495810 31435 replica.cpp:712] Persisted action at 1
I0111 23:57:32.495853 31435 replica.cpp:697] Replica learned APPEND action at position 1
I0111 23:57:32.497371 31440 registrar.cpp:484] Successfully updated the 'registry' in 70.377984ms
I0111 23:57:32.497548 31440 registrar.cpp:370] Successfully recovered registrar
I0111 23:57:32.497750 31435 log.cpp:702] Attempting to truncate the log to 1
I0111 23:57:32.498004 31435 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0111 23:57:32.498109 31441 master.cpp:1525] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0111 23:57:32.498306 31441 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0111 23:57:32.499186 31435 replica.cpp:537] Replica received write request for position 2 from (13483)@172.17.0.3:59578
I0111 23:57:32.523279 31435 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.019033ms
I0111 23:57:32.523372 31435 replica.cpp:712] Persisted action at 2
I0111 23:57:32.526496 31441 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0111 23:57:32.548465 31441 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 21.906827ms
I0111 23:57:32.548619 31441 leveldb.cpp:399] Deleting ~1 keys from leveldb took 66086ns
I0111 23:57:32.548647 31441 replica.cpp:712] Persisted action at 2
I0111 23:57:32.548687 31441 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0111 23:57:32.559959 31415 scheduler.cpp:154] Version: 0.27.0
I0111 23:57:32.560937 31443 scheduler.cpp:236] New master detected at master@172.17.0.3:59578
I0111 23:57:32.562489 31438 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.3:59578
I0111 23:57:32.565389 31435 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0111 23:57:32.566109 31437 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:51957
I0111 23:57:32.566499 31437 master.cpp:1977] Received subscription request for HTTP framework 'default'
I0111 23:57:32.566581 31437 master.cpp:1754] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0111 23:57:32.566901 31437 master.cpp:2068] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0111 23:57:32.567350 31447 hierarchical.cpp:260] Added framework ecb54e3e-dd13-4727-8e1b-18af47e6f312-0000
I0111 23:57:32.567414 31448 master.hpp:1657] Sending heartbeat to ecb54e3e-dd13-4727-8e1b-18af47e6f312-0000
I0111 23:57:32.567432 31447 hierarchical.cpp:1329] No resources available to allocate!
I0111 23:57:32.567466 31447 hierarchical.cpp:1423] No inverse offers to send out!
I0111 23:57:32.567488 31447 hierarchical.cpp:1079] Performed allocation for 0 slaves in 110108ns
I0111 23:57:32.568382 31448 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.3:59578
I0111 23:57:32.568794 31448 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.3:59578
I0111 23:57:32.569504 31441 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0111 23:57:32.569551 31448 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.3:59578
I0111 23:57:32.571099 31440 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0111 23:57:32.571476 31438 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:51958
I0111 23:57:32.571701 31438 master.cpp:2722] Processing REQUEST call for framework ecb54e3e-dd13-4727-8e1b-18af47e6f312-0000 (default)
I0111 23:57:32.571864 31442 hierarchical.cpp:579] Received resource request from framework ecb54e3e-dd13-4727-8e1b-18af47e6f312-0000
I0111 23:57:32.572212 31443 master.cpp:1016] Master terminating
I0111 23:57:32.572499 31436 hierarchical.cpp:321] Removed framework ecb54e3e-dd13-4727-8e1b-18af47e6f312-0000
E0111 23:57:32.573555 31438 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (681 ms)
[----------] 22 tests from ContentType/SchedulerTest (18838 ms total)
[----------] Global test environment tear-down
2016-01-11 23:57:33,081:31415(0x2b2b7060b700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:58239] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
[==========] 925 tests from 122 test cases ran. (954434 ms total)
[ PASSED ] 924 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] PersistentVolumeTest.BadACLDropCreateAndDestroy
1 FAILED TEST
YOU HAVE 7 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1452553201-6811
Untagged: mesos-1452553201-6811:latest
Deleted: 67de5469b0c886aed8ea2e88065c5d200e53965bbdd75e1588009ba7bca557cd
Deleted: 9fb8ebe380f8971f14425b3c74338c24ac1c57f94cc08d2f4119ac5b8856f6d7
Deleted: 0cd87b972b7baed5029fe700c7d35fafdc1a80f7876f8447c21e6a6f7a7765fc
Deleted: 20848de235c3136932a290f3959257dea1c19b24613195eb89697c7503c1223a
Deleted: 8c905adb55370c60781f8fb79527dbe19c6582570fd3338aec9be6e01b89d00e
Deleted: d460f10d6f421af83cbe5a263a9a7082ccf77a2e5369e19712935895287df382
Deleted: f660824d3431abd8857e9c7e3430a11555f3341307eb18003b23328ff597028a
Deleted: 2535c517bf7c05274f4cb253e43472ed61e27000a6006ccc2c71dbf6fe79c984
Deleted: 025e3da1136fe7b72ef995cb0b1b5e82dc8587c6a4de95a2b169d2f6175b4c7c
Deleted: 422538a3cbc20a05d3202166b7f96ed3a6d57b9780943042b0c1b1eb835fc02d
Deleted: ef94d2976808ae915d79334691d0f6b5e319faeeeeaf4461a96736ed433cc7c0
Deleted: 539ccea5e5896d9f004a25e00fff2566b1e4f66779cec135cd4ed602a1213e06
Deleted: 445e0322e76db61e4c65d210d660343c6edd8846ac5682e3e1b4ba9e2f07e52b
Deleted: 254231230ee27ca3e93fa8d69a16fcbc2f42a5d04b90323bbf3f1ce30a49f67a
Error handling URL https://reviews.apache.org/api/review-requests/42040/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard 521dbb6c91affddf3ed6dc1e00c885215e5a7343
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: mesos-reviewbot #10723
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10723/>
------------------------------------------
[...truncated 167464 lines...]
I0111 22:26:32.462340 31444 master.cpp:372] Master 40d1cc3d-a923-420f-b387-11621ed007ab (e75b17ab157b) started on 172.17.0.3:53507
I0111 22:26:32.462400 31438 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0111 22:26:32.462365 31444 master.cpp:374] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/9KYFkI/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_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/9KYFkI/master" --zk_session_timeout="10secs"
I0111 22:26:32.462796 31444 master.cpp:421] Master allowing unauthenticated frameworks to register
I0111 22:26:32.462808 31444 master.cpp:424] Master only allowing authenticated slaves to register
I0111 22:26:32.462818 31444 credentials.hpp:35] Loading credentials for authentication from '/tmp/9KYFkI/credentials'
I0111 22:26:32.463076 31441 recover.cpp:564] Updating replica status to STARTING
I0111 22:26:32.463307 31444 master.cpp:464] Using default 'crammd5' authenticator
I0111 22:26:32.463488 31444 master.cpp:533] Using default 'basic' HTTP authenticator
I0111 22:26:32.463929 31444 master.cpp:567] Authorization enabled
I0111 22:26:32.464315 31432 hierarchical.cpp:147] Initialized hierarchical allocator process
I0111 22:26:32.464396 31432 whitelist_watcher.cpp:77] No whitelist given
I0111 22:26:32.466722 31439 master.cpp:1715] The newly elected leader is master@172.17.0.3:53507 with id 40d1cc3d-a923-420f-b387-11621ed007ab
I0111 22:26:32.466770 31439 master.cpp:1728] Elected as the leading master!
I0111 22:26:32.466789 31439 master.cpp:1473] Recovering from registrar
I0111 22:26:32.467286 31431 registrar.cpp:307] Recovering registrar
I0111 22:26:32.505796 31438 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 42.527194ms
I0111 22:26:32.505883 31438 replica.cpp:320] Persisted replica status to STARTING
I0111 22:26:32.506297 31431 recover.cpp:473] Replica is in STARTING status
I0111 22:26:32.507870 31437 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13431)@172.17.0.3:53507
I0111 22:26:32.508158 31434 recover.cpp:193] Received a recover response from a replica in STARTING status
I0111 22:26:32.508599 31437 recover.cpp:564] Updating replica status to VOTING
I0111 22:26:32.572845 31433 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 63.955795ms
I0111 22:26:32.572931 31433 replica.cpp:320] Persisted replica status to VOTING
I0111 22:26:32.573221 31433 recover.cpp:578] Successfully joined the Paxos group
I0111 22:26:32.573431 31433 recover.cpp:462] Recover process terminated
I0111 22:26:32.574208 31433 log.cpp:659] Attempting to start the writer
I0111 22:26:32.576122 31433 replica.cpp:493] Replica received implicit promise request from (13432)@172.17.0.3:53507 with proposal 1
I0111 22:26:32.607689 31433 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.512867ms
I0111 22:26:32.607770 31433 replica.cpp:342] Persisted promised to 1
I0111 22:26:32.608649 31444 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0111 22:26:32.610067 31436 replica.cpp:388] Replica received explicit promise request from (13433)@172.17.0.3:53507 for position 0 with proposal 2
I0111 22:26:32.642344 31436 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 32.21067ms
I0111 22:26:32.642427 31436 replica.cpp:712] Persisted action at 0
I0111 22:26:32.643892 31443 replica.cpp:537] Replica received write request for position 0 from (13434)@172.17.0.3:53507
I0111 22:26:32.643980 31443 leveldb.cpp:436] Reading position from leveldb took 47590ns
I0111 22:26:32.667843 31443 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.790527ms
I0111 22:26:32.667954 31443 replica.cpp:712] Persisted action at 0
I0111 22:26:32.669340 31438 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0111 22:26:32.709823 31438 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.385411ms
I0111 22:26:32.709916 31438 replica.cpp:712] Persisted action at 0
I0111 22:26:32.709956 31438 replica.cpp:697] Replica learned NOP action at position 0
I0111 22:26:32.711284 31438 log.cpp:675] Writer started with ending position 0
I0111 22:26:32.712916 31438 leveldb.cpp:436] Reading position from leveldb took 63340ns
I0111 22:26:32.714499 31432 registrar.cpp:340] Successfully fetched the registry (0B) in 247.14496ms
I0111 22:26:32.714740 31432 registrar.cpp:439] Applied 1 operations in 44717ns; attempting to update the 'registry'
I0111 22:26:32.716239 31430 log.cpp:683] Attempting to append 170 bytes to the log
I0111 22:26:32.716516 31430 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0111 22:26:32.717680 31430 replica.cpp:537] Replica received write request for position 1 from (13435)@172.17.0.3:53507
I0111 22:26:32.751797 31430 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 34.043023ms
I0111 22:26:32.751888 31430 replica.cpp:712] Persisted action at 1
I0111 22:26:32.753435 31430 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0111 22:26:32.777207 31430 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 23.715564ms
I0111 22:26:32.777297 31430 replica.cpp:712] Persisted action at 1
I0111 22:26:32.777335 31430 replica.cpp:697] Replica learned APPEND action at position 1
I0111 22:26:32.778887 31432 registrar.cpp:484] Successfully updated the 'registry' in 63.992064ms
I0111 22:26:32.779064 31432 registrar.cpp:370] Successfully recovered registrar
I0111 22:26:32.779233 31430 log.cpp:702] Attempting to truncate the log to 1
I0111 22:26:32.779445 31430 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0111 22:26:32.779541 31432 master.cpp:1525] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0111 22:26:32.779719 31432 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0111 22:26:32.780519 31444 replica.cpp:537] Replica received write request for position 2 from (13436)@172.17.0.3:53507
I0111 22:26:32.807948 31444 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 27.364321ms
I0111 22:26:32.808034 31444 replica.cpp:712] Persisted action at 2
I0111 22:26:32.808959 31444 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0111 22:26:32.858312 31444 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 49.288571ms
I0111 22:26:32.858464 31444 leveldb.cpp:399] Deleting ~1 keys from leveldb took 69494ns
I0111 22:26:32.858494 31444 replica.cpp:712] Persisted action at 2
I0111 22:26:32.858533 31444 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0111 22:26:32.861484 31411 scheduler.cpp:154] Version: 0.27.0
I0111 22:26:32.862162 31434 scheduler.cpp:236] New master detected at master@172.17.0.3:53507
I0111 22:26:32.863276 31434 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.3:53507
I0111 22:26:32.865624 31434 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0111 22:26:32.866195 31439 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:53519
I0111 22:26:32.866384 31439 master.cpp:1977] Received subscription request for HTTP framework 'default'
I0111 22:26:32.866451 31439 master.cpp:1754] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0111 22:26:32.866703 31439 master.cpp:2068] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0111 22:26:32.867187 31433 master.hpp:1657] Sending heartbeat to 40d1cc3d-a923-420f-b387-11621ed007ab-0000
I0111 22:26:32.867215 31440 hierarchical.cpp:260] Added framework 40d1cc3d-a923-420f-b387-11621ed007ab-0000
I0111 22:26:32.867295 31440 hierarchical.cpp:1329] No resources available to allocate!
I0111 22:26:32.867336 31440 hierarchical.cpp:1423] No inverse offers to send out!
I0111 22:26:32.867367 31440 hierarchical.cpp:1079] Performed allocation for 0 slaves in 128526ns
I0111 22:26:32.868259 31437 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.3:53507
I0111 22:26:32.868805 31437 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.3:53507
I0111 22:26:32.869478 31439 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0111 22:26:32.869576 31437 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.3:53507
I0111 22:26:32.871886 31440 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0111 22:26:32.872470 31430 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:53520
I0111 22:26:32.872642 31430 master.cpp:2722] Processing REQUEST call for framework 40d1cc3d-a923-420f-b387-11621ed007ab-0000 (default)
I0111 22:26:32.872812 31443 hierarchical.cpp:579] Received resource request from framework 40d1cc3d-a923-420f-b387-11621ed007ab-0000
I0111 22:26:32.873272 31430 master.cpp:1016] Master terminating
I0111 22:26:32.873603 31433 hierarchical.cpp:321] Removed framework 40d1cc3d-a923-420f-b387-11621ed007ab-0000
E0111 22:26:32.875000 31440 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (633 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0111 22:26:33.013111 31411 leveldb.cpp:174] Opened db in 130.732653ms
I0111 22:26:33.055157 31411 leveldb.cpp:181] Compacted db in 41.954175ms
I0111 22:26:33.055253 31411 leveldb.cpp:196] Created db iterator in 26060ns
I0111 22:26:33.055277 31411 leveldb.cpp:202] Seeked to beginning of db in 3195ns
I0111 22:26:33.055290 31411 leveldb.cpp:271] Iterated through 0 keys in the db in 365ns
I0111 22:26:33.055349 31411 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0111 22:26:33.056253 31434 recover.cpp:447] Starting replica recovery
I0111 22:26:33.056545 31434 recover.cpp:473] Replica is in EMPTY status
I0111 22:26:33.057756 31442 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13444)@172.17.0.3:53507
I0111 22:26:33.058264 31430 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0111 22:26:33.058917 31438 recover.cpp:564] Updating replica status to STARTING
I0111 22:26:33.060817 31441 master.cpp:372] Master c1ecb074-31af-42bc-87b0-0e9414e190c5 (e75b17ab157b) started on 172.17.0.3:53507
I0111 22:26:33.060848 31441 master.cpp:374] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/CSGmGa/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_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/CSGmGa/master" --zk_session_timeout="10secs"
I0111 22:26:33.061260 31441 master.cpp:421] Master allowing unauthenticated frameworks to register
I0111 22:26:33.061275 31441 master.cpp:424] Master only allowing authenticated slaves to register
I0111 22:26:33.061283 31441 credentials.hpp:35] Loading credentials for authentication from '/tmp/CSGmGa/credentials'
I0111 22:26:33.061691 31441 master.cpp:464] Using default 'crammd5' authenticator
I0111 22:26:33.061851 31441 master.cpp:533] Using default 'basic' HTTP authenticator
I0111 22:26:33.062027 31441 master.cpp:567] Authorization enabled
I0111 22:26:33.062216 31431 whitelist_watcher.cpp:77] No whitelist given
I0111 22:26:33.062216 31436 hierarchical.cpp:147] Initialized hierarchical allocator process
I0111 22:26:33.064427 31432 master.cpp:1715] The newly elected leader is master@172.17.0.3:53507 with id c1ecb074-31af-42bc-87b0-0e9414e190c5
I0111 22:26:33.064465 31432 master.cpp:1728] Elected as the leading master!
I0111 22:26:33.064487 31432 master.cpp:1473] Recovering from registrar
I0111 22:26:33.064630 31444 registrar.cpp:307] Recovering registrar
I0111 22:26:33.109774 31430 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 50.716534ms
I0111 22:26:33.109856 31430 replica.cpp:320] Persisted replica status to STARTING
I0111 22:26:33.110292 31432 recover.cpp:473] Replica is in STARTING status
I0111 22:26:33.112157 31445 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13446)@172.17.0.3:53507
I0111 22:26:33.113098 31440 recover.cpp:193] Received a recover response from a replica in STARTING status
I0111 22:26:33.113800 31441 recover.cpp:564] Updating replica status to VOTING
I0111 22:26:33.168202 31439 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 54.114992ms
I0111 22:26:33.168282 31439 replica.cpp:320] Persisted replica status to VOTING
I0111 22:26:33.168447 31430 recover.cpp:578] Successfully joined the Paxos group
I0111 22:26:33.169217 31432 log.cpp:659] Attempting to start the writer
I0111 22:26:33.169502 31430 recover.cpp:462] Recover process terminated
I0111 22:26:33.171335 31440 replica.cpp:493] Replica received implicit promise request from (13447)@172.17.0.3:53507 with proposal 1
I0111 22:26:33.201768 31440 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.355672ms
I0111 22:26:33.201860 31440 replica.cpp:342] Persisted promised to 1
I0111 22:26:33.203225 31436 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0111 22:26:33.204849 31441 replica.cpp:388] Replica received explicit promise request from (13448)@172.17.0.3:53507 for position 0 with proposal 2
I0111 22:26:33.235365 31441 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 30.445027ms
I0111 22:26:33.235450 31441 replica.cpp:712] Persisted action at 0
I0111 22:26:33.236874 31445 replica.cpp:537] Replica received write request for position 0 from (13449)@172.17.0.3:53507
I0111 22:26:33.236969 31445 leveldb.cpp:436] Reading position from leveldb took 46976ns
I0111 22:26:33.302222 31445 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 65.176134ms
I0111 22:26:33.302314 31445 replica.cpp:712] Persisted action at 0
I0111 22:26:33.303172 31432 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0111 22:26:33.402860 31432 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 99.629149ms
I0111 22:26:33.402956 31432 replica.cpp:712] Persisted action at 0
I0111 22:26:33.403012 31432 replica.cpp:697] Replica learned NOP action at position 0
I0111 22:26:33.403926 31430 log.cpp:675] Writer started with ending position 0
I0111 22:26:33.405200 31436 leveldb.cpp:436] Reading position from leveldb took 59897ns
I0111 22:26:33.406414 31436 registrar.cpp:340] Successfully fetched the registry (0B) in 341.735168ms
I0111 22:26:33.406565 31436 registrar.cpp:439] Applied 1 operations in 40335ns; attempting to update the 'registry'
I0111 22:26:33.407639 31435 log.cpp:683] Attempting to append 170 bytes to the log
I0111 22:26:33.407789 31439 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0111 22:26:33.408810 31439 replica.cpp:537] Replica received write request for position 1 from (13450)@172.17.0.3:53507
I0111 22:26:33.521642 31439 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 112.765421ms
I0111 22:26:33.521729 31439 replica.cpp:712] Persisted action at 1
I0111 22:26:33.522610 31432 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0111 22:26:33.569780 31432 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 47.120087ms
I0111 22:26:33.569859 31432 replica.cpp:712] Persisted action at 1
I0111 22:26:33.569905 31432 replica.cpp:697] Replica learned APPEND action at position 1
I0111 22:26:33.571205 31431 registrar.cpp:484] Successfully updated the 'registry' in 164.569856ms
I0111 22:26:33.571373 31431 registrar.cpp:370] Successfully recovered registrar
I0111 22:26:33.571499 31433 log.cpp:702] Attempting to truncate the log to 1
I0111 22:26:33.571683 31433 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0111 22:26:33.571795 31431 master.cpp:1525] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0111 22:26:33.571979 31431 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0111 22:26:33.572715 31433 replica.cpp:537] Replica received write request for position 2 from (13451)@172.17.0.3:53507
I0111 22:26:33.603502 31433 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 30.721773ms
I0111 22:26:33.603597 31433 replica.cpp:712] Persisted action at 2
I0111 22:26:33.604993 31433 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0111 22:26:33.628787 31433 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 23.732113ms
I0111 22:26:33.628940 31433 leveldb.cpp:399] Deleting ~1 keys from leveldb took 69148ns
I0111 22:26:33.628980 31433 replica.cpp:712] Persisted action at 2
I0111 22:26:33.629019 31433 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0111 22:26:33.633714 31411 scheduler.cpp:154] Version: 0.27.0
I0111 22:26:33.634519 31441 scheduler.cpp:236] New master detected at master@172.17.0.3:53507
I0111 22:26:33.635663 31430 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.3:53507
I0111 22:26:33.637970 31442 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0111 22:26:33.638535 31442 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:53532
I0111 22:26:33.638849 31442 master.cpp:1977] Received subscription request for HTTP framework 'default'
I0111 22:26:33.638903 31442 master.cpp:1754] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0111 22:26:33.639158 31442 master.cpp:2068] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0111 22:26:33.639678 31432 hierarchical.cpp:260] Added framework c1ecb074-31af-42bc-87b0-0e9414e190c5-0000
I0111 22:26:33.639788 31432 hierarchical.cpp:1329] No resources available to allocate!
I0111 22:26:33.639833 31432 hierarchical.cpp:1423] No inverse offers to send out!
I0111 22:26:33.639866 31432 hierarchical.cpp:1079] Performed allocation for 0 slaves in 142201ns
I0111 22:26:33.640416 31444 master.hpp:1657] Sending heartbeat to c1ecb074-31af-42bc-87b0-0e9414e190c5-0000
I0111 22:26:33.641597 31430 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.3:53507
I0111 22:26:33.642189 31430 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.3:53507
I0111 22:26:33.642781 31441 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0111 22:26:33.643018 31430 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.3:53507
I0111 22:26:33.645311 31432 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0111 22:26:33.645808 31432 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:53533
I0111 22:26:33.646159 31432 master.cpp:2722] Processing REQUEST call for framework c1ecb074-31af-42bc-87b0-0e9414e190c5-0000 (default)
I0111 22:26:33.646329 31431 hierarchical.cpp:579] Received resource request from framework c1ecb074-31af-42bc-87b0-0e9414e190c5-0000
I0111 22:26:33.646745 31439 master.cpp:1016] Master terminating
I0111 22:26:33.647064 31441 hierarchical.cpp:321] Removed framework c1ecb074-31af-42bc-87b0-0e9414e190c5-0000
E0111 22:26:33.649147 31435 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (775 ms)
[----------] 22 tests from ContentType/SchedulerTest (20221 ms total)
[----------] Global test environment tear-down
2016-01-11 22:26:34,391:31411(0x2b653c81d700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:40779] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
[==========] 925 tests from 122 test cases ran. (798717 ms total)
[ PASSED ] 916 tests.
[ FAILED ] 9 tests, listed below:
[ FAILED ] FetcherCacheTest.LocalCached
[ FAILED ] FetcherCacheTest.CachedFallback
[ FAILED ] FetcherCacheTest.LocalCachedExtract
[ FAILED ] FetcherCacheTest.SimpleEviction
[ FAILED ] FetcherCacheTest.FallbackFromEviction
[ FAILED ] FetcherCacheTest.RemoveLRUCacheEntries
[ FAILED ] FetcherCacheHttpTest.HttpCachedSerialized
[ FAILED ] FetcherCacheHttpTest.HttpCachedConcurrent
[ FAILED ] FetcherCacheHttpTest.HttpMixed
9 FAILED TESTS
YOU HAVE 7 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[3]: *** [check-am] Error 2
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
make[1]: *** [check-recursive] Error 1
make: *** [distcheck] Error 1
+ docker rmi mesos-1452548608-26681
Untagged: mesos-1452548608-26681:latest
Deleted: 6d3045e46b1132529fc782085ee6dcd028af5ddf09ba972b714d6dce737cd8db
Deleted: 262f115d615a199f9704e42cb833fa1c135eedd5157cad049d4346b2b03044c0
Deleted: ea11d245eebfc7f2eea370fb01677246a392f2d7abc4175d68d6a72c746b1b24
Deleted: f8da9174235d7602d780e5c3ce41c66645cb1030236c248b3016140137735863
Deleted: 99ad2758646d439e3441bdc7e6b87fef6dbbb04510f587f65b90934d508fa403
Deleted: 3bbc9633ab1faef47036922e81b1c856bd8582fa543891aaf5a89d1f4134cc0e
Deleted: 76557fc124d92fe37d492b8365e10792465dcb69a29f9aea9cd37809d7db55c2
Deleted: 12244f61f4981b77b8fffbfc207ba74f8fe335a2557bc7df427cf5dce789edb9
Deleted: 1299c5878a9e27effddfcbc99c86fd19d0c5079bc3a8051c36a66c5372f8663d
Deleted: 7cdcd0d677f75b1d3f3e241366d70e8391476cf663d2b6f0bb2cbccc5be368a7
Deleted: 431ab2e29eb5e4302928b2c14cae1a9fc69057a035d7b9bd3e97b960b2a441e3
Deleted: 997823985af672d6dfc0e2111c8fcbe170ef570a5a3a68ae47ef3cafd3286f14
Deleted: cf2901643b9669134c23fb676fb47f1b6194dd7c0ed2ed866671f4c954661b29
Deleted: d3b7a98ef3c879357b5a166018bd3f68805ce781f2836febc91bec9af6ea6d9e
Error handling URL https://reviews.apache.org/api/review-requests/41590/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard 521dbb6c91affddf3ed6dc1e00c885215e5a7343
Build step 'Execute shell' marked build as failure