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/03/03 07:21:52 UTC
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(docker||Hadoop)&&(!ubuntu-us1) #1764
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)/1764/changes>
Changes:
[bmahler] Updated /metrics/snapshot rate limiting to be configurable.
[bmahler] Documented LIBPROCESS_METRICS_SNAPSHOT_ENDPOINT_RATE_LIMIT.
[bmahler] Disabled rate limiting of /metrics/snapshot in the mesos tests.
[bmahler] Updated tests now that /metrics/snapshot is not rate limited.
------------------------------------------
[...truncated 170577 lines...]
I0303 06:21:51.610836 2234 master.cpp:375] Master 403ebe00-783a-4f1e-91a8-281176aedd14 (9f1aab485eac) started on 172.17.0.2:38514
I0303 06:21:51.610884 2234 master.cpp:377] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/XOGdhd/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="100secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/XOGdhd/master" --zk_session_timeout="10secs"
I0303 06:21:51.611284 2234 master.cpp:424] Master allowing unauthenticated frameworks to register
I0303 06:21:51.611295 2234 master.cpp:427] Master only allowing authenticated slaves to register
I0303 06:21:51.611304 2234 credentials.hpp:35] Loading credentials for authentication from '/tmp/XOGdhd/credentials'
I0303 06:21:51.611708 2234 master.cpp:467] Using default 'crammd5' authenticator
I0303 06:21:51.611886 2234 master.cpp:536] Using default 'basic' HTTP authenticator
I0303 06:21:51.612021 2234 master.cpp:570] Authorization enabled
I0303 06:21:51.614553 2238 hierarchical.cpp:144] Initialized hierarchical allocator process
I0303 06:21:51.614665 2238 whitelist_watcher.cpp:77] No whitelist given
I0303 06:21:51.616646 2234 master.cpp:1711] The newly elected leader is master@172.17.0.2:38514 with id 403ebe00-783a-4f1e-91a8-281176aedd14
I0303 06:21:51.616809 2234 master.cpp:1724] Elected as the leading master!
I0303 06:21:51.616961 2234 master.cpp:1469] Recovering from registrar
I0303 06:21:51.617331 2224 registrar.cpp:307] Recovering registrar
I0303 06:21:51.638227 2232 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 29.322145ms
I0303 06:21:51.638325 2232 replica.cpp:320] Persisted replica status to STARTING
I0303 06:21:51.638736 2235 recover.cpp:473] Replica is in STARTING status
I0303 06:21:51.640202 2239 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (15016)@172.17.0.2:38514
I0303 06:21:51.640682 2232 recover.cpp:193] Received a recover response from a replica in STARTING status
I0303 06:21:51.641229 2239 recover.cpp:564] Updating replica status to VOTING
I0303 06:21:51.663300 2239 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 21.821138ms
I0303 06:21:51.663398 2239 replica.cpp:320] Persisted replica status to VOTING
I0303 06:21:51.663643 2232 recover.cpp:578] Successfully joined the Paxos group
I0303 06:21:51.663903 2232 recover.cpp:462] Recover process terminated
I0303 06:21:51.664634 2236 log.cpp:659] Attempting to start the writer
I0303 06:21:51.666277 2232 replica.cpp:493] Replica received implicit promise request from (15017)@172.17.0.2:38514 with proposal 1
I0303 06:21:51.688403 2232 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.051863ms
I0303 06:21:51.688501 2232 replica.cpp:342] Persisted promised to 1
I0303 06:21:51.689961 2232 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0303 06:21:51.691828 2232 replica.cpp:388] Replica received explicit promise request from (15018)@172.17.0.2:38514 for position 0 with proposal 2
I0303 06:21:51.713541 2232 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 21.629297ms
I0303 06:21:51.713637 2232 replica.cpp:712] Persisted action at 0
I0303 06:21:51.715340 2226 replica.cpp:537] Replica received write request for position 0 from (15019)@172.17.0.2:38514
I0303 06:21:51.715445 2226 leveldb.cpp:436] Reading position from leveldb took 47971ns
I0303 06:21:51.738667 2226 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.144203ms
I0303 06:21:51.738767 2226 replica.cpp:712] Persisted action at 0
I0303 06:21:51.739928 2226 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0303 06:21:51.763761 2226 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 23.779433ms
I0303 06:21:51.763859 2226 replica.cpp:712] Persisted action at 0
I0303 06:21:51.763897 2226 replica.cpp:697] Replica learned NOP action at position 0
I0303 06:21:51.765213 2226 log.cpp:675] Writer started with ending position 0
I0303 06:21:51.766810 2226 leveldb.cpp:436] Reading position from leveldb took 68416ns
I0303 06:21:51.768328 2225 registrar.cpp:340] Successfully fetched the registry (0B) in 150.892032ms
I0303 06:21:51.768558 2225 registrar.cpp:439] Applied 1 operations in 41998ns; attempting to update the 'registry'
I0303 06:21:51.770032 2225 log.cpp:683] Attempting to append 170 bytes to the log
I0303 06:21:51.770393 2225 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0303 06:21:51.771659 2225 replica.cpp:537] Replica received write request for position 1 from (15020)@172.17.0.2:38514
I0303 06:21:51.797233 2225 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 25.430731ms
I0303 06:21:51.797332 2225 replica.cpp:712] Persisted action at 1
I0303 06:21:51.798856 2225 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0303 06:21:51.813995 2225 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 15.08501ms
I0303 06:21:51.814091 2225 replica.cpp:712] Persisted action at 1
I0303 06:21:51.814129 2225 replica.cpp:697] Replica learned APPEND action at position 1
I0303 06:21:51.816200 2225 registrar.cpp:484] Successfully updated the 'registry' in 47488us
I0303 06:21:51.816423 2225 registrar.cpp:370] Successfully recovered registrar
I0303 06:21:51.816704 2225 log.cpp:702] Attempting to truncate the log to 1
I0303 06:21:51.817173 2225 master.cpp:1521] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0303 06:21:51.817281 2225 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0303 06:21:51.817826 2235 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0303 06:21:51.818732 2236 replica.cpp:537] Replica received write request for position 2 from (15021)@172.17.0.2:38514
I0303 06:21:51.839108 2236 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 20.309168ms
I0303 06:21:51.839201 2236 replica.cpp:712] Persisted action at 2
I0303 06:21:51.840302 2236 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0303 06:21:51.871496 2236 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 31.136875ms
I0303 06:21:51.871657 2236 leveldb.cpp:399] Deleting ~1 keys from leveldb took 74569ns
I0303 06:21:51.871683 2236 replica.cpp:712] Persisted action at 2
I0303 06:21:51.871718 2236 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0303 06:21:51.879359 2205 scheduler.cpp:172] Version: 0.28.0
I0303 06:21:51.880163 2228 scheduler.cpp:432] New master detected at master@172.17.0.2:38514
I0303 06:21:51.882194 2228 scheduler.cpp:332] Connected with the master at http://172.17.0.2:38514/master/api/v1/scheduler
I0303 06:21:51.883528 2228 scheduler.cpp:230] Sending SUBSCRIBE call to http://172.17.0.2:38514/master/api/v1/scheduler
I0303 06:21:51.884737 2228 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 06:21:51.885289 2228 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:43389
I0303 06:21:51.885489 2228 master.cpp:1973] Received subscription request for HTTP framework 'default'
I0303 06:21:51.885557 2228 master.cpp:1750] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0303 06:21:51.886227 2228 master.cpp:2064] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0303 06:21:51.887198 2228 hierarchical.cpp:265] Added framework 403ebe00-783a-4f1e-91a8-281176aedd14-0000
I0303 06:21:51.887297 2228 hierarchical.cpp:1453] No resources available to allocate!
I0303 06:21:51.887334 2228 hierarchical.cpp:1548] No inverse offers to send out!
I0303 06:21:51.887359 2228 hierarchical.cpp:1130] Performed allocation for 0 slaves in 126340ns
I0303 06:21:51.887548 2228 master.hpp:1657] Sending heartbeat to 403ebe00-783a-4f1e-91a8-281176aedd14-0000
I0303 06:21:51.888756 2228 scheduler.cpp:602] Enqueuing event SUBSCRIBED received from http://172.17.0.2:38514/master/api/v1/scheduler
I0303 06:21:51.889554 2228 scheduler.cpp:602] Enqueuing event HEARTBEAT received from http://172.17.0.2:38514/master/api/v1/scheduler
I0303 06:21:51.890166 2228 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0303 06:21:51.890678 2237 scheduler.cpp:230] Sending REQUEST call to http://172.17.0.2:38514/master/api/v1/scheduler
I0303 06:21:51.891865 2237 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 06:21:51.892370 2237 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:43390
I0303 06:21:51.892477 2237 master.cpp:2670] Processing REQUEST call for framework 403ebe00-783a-4f1e-91a8-281176aedd14-0000 (default)
I0303 06:21:51.892707 2237 hierarchical.cpp:589] Received resource request from framework 403ebe00-783a-4f1e-91a8-281176aedd14-0000
I0303 06:21:51.893460 2205 master.cpp:1026] Master terminating
I0303 06:21:51.893667 2225 hierarchical.cpp:326] Removed framework 403ebe00-783a-4f1e-91a8-281176aedd14-0000
E0303 06:21:51.895331 2225 scheduler.cpp:575] End-Of-File received from master. The master closed the event stream
I0303 06:21:51.896739 2233 scheduler.cpp:414] Re-detecting master
I0303 06:21:51.897099 2233 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 06:21:51.897138 2233 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 06:21:51.897234 2233 scheduler.cpp:432] New master detected at master@172.17.0.2:38514
I0303 06:21:51.899335 2231 scheduler.cpp:332] Connected with the master at http://172.17.0.2:38514/master/api/v1/scheduler
[ OK ] ContentType/SchedulerTest.Request/0 (461 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0303 06:21:52.040698 2205 leveldb.cpp:174] Opened db in 132.105756ms
I0303 06:21:52.089633 2205 leveldb.cpp:181] Compacted db in 48.843722ms
I0303 06:21:52.089741 2205 leveldb.cpp:196] Created db iterator in 28577ns
I0303 06:21:52.089761 2205 leveldb.cpp:202] Seeked to beginning of db in 3274ns
I0303 06:21:52.089773 2205 leveldb.cpp:271] Iterated through 0 keys in the db in 352ns
I0303 06:21:52.089830 2205 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0303 06:21:52.090765 2226 recover.cpp:447] Starting replica recovery
I0303 06:21:52.091087 2226 recover.cpp:473] Replica is in EMPTY status
I0303 06:21:52.092880 2226 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (15029)@172.17.0.2:38514
I0303 06:21:52.093297 2230 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0303 06:21:52.094068 2230 recover.cpp:564] Updating replica status to STARTING
I0303 06:21:52.100342 2225 master.cpp:375] Master d7e2d687-e074-48e0-9ead-e31d14d0cbca (9f1aab485eac) started on 172.17.0.2:38514
I0303 06:21:52.100389 2225 master.cpp:377] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/sJvbob/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="100secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/sJvbob/master" --zk_session_timeout="10secs"
I0303 06:21:52.100774 2225 master.cpp:424] Master allowing unauthenticated frameworks to register
I0303 06:21:52.100785 2225 master.cpp:427] Master only allowing authenticated slaves to register
I0303 06:21:52.100795 2225 credentials.hpp:35] Loading credentials for authentication from '/tmp/sJvbob/credentials'
I0303 06:21:52.101168 2225 master.cpp:467] Using default 'crammd5' authenticator
I0303 06:21:52.101518 2225 master.cpp:536] Using default 'basic' HTTP authenticator
I0303 06:21:52.101675 2225 master.cpp:570] Authorization enabled
I0303 06:21:52.101866 2232 whitelist_watcher.cpp:77] No whitelist given
I0303 06:21:52.101905 2224 hierarchical.cpp:144] Initialized hierarchical allocator process
I0303 06:21:52.107416 2225 master.cpp:1711] The newly elected leader is master@172.17.0.2:38514 with id d7e2d687-e074-48e0-9ead-e31d14d0cbca
I0303 06:21:52.107604 2225 master.cpp:1724] Elected as the leading master!
I0303 06:21:52.107802 2225 master.cpp:1469] Recovering from registrar
I0303 06:21:52.108054 2224 registrar.cpp:307] Recovering registrar
I0303 06:21:52.156242 2230 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 61.854255ms
I0303 06:21:52.156328 2230 replica.cpp:320] Persisted replica status to STARTING
I0303 06:21:52.156687 2230 recover.cpp:473] Replica is in STARTING status
I0303 06:21:52.158763 2230 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (15031)@172.17.0.2:38514
I0303 06:21:52.159173 2230 recover.cpp:193] Received a recover response from a replica in STARTING status
I0303 06:21:52.159890 2230 recover.cpp:564] Updating replica status to VOTING
I0303 06:21:52.181362 2230 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 21.22021ms
I0303 06:21:52.181443 2230 replica.cpp:320] Persisted replica status to VOTING
I0303 06:21:52.181704 2230 recover.cpp:578] Successfully joined the Paxos group
I0303 06:21:52.181903 2230 recover.cpp:462] Recover process terminated
I0303 06:21:52.182706 2230 log.cpp:659] Attempting to start the writer
I0303 06:21:52.184407 2230 replica.cpp:493] Replica received implicit promise request from (15032)@172.17.0.2:38514 with proposal 1
I0303 06:21:52.206504 2230 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.038339ms
I0303 06:21:52.206588 2230 replica.cpp:342] Persisted promised to 1
I0303 06:21:52.208233 2230 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0303 06:21:52.209913 2232 replica.cpp:388] Replica received explicit promise request from (15033)@172.17.0.2:38514 for position 0 with proposal 2
I0303 06:21:52.231662 2232 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 21.667572ms
I0303 06:21:52.231751 2232 replica.cpp:712] Persisted action at 0
I0303 06:21:52.233633 2232 replica.cpp:537] Replica received write request for position 0 from (15034)@172.17.0.2:38514
I0303 06:21:52.233716 2232 leveldb.cpp:436] Reading position from leveldb took 45026ns
I0303 06:21:52.256826 2232 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.045233ms
I0303 06:21:52.256921 2232 replica.cpp:712] Persisted action at 0
I0303 06:21:52.258198 2232 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0303 06:21:52.281967 2232 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 23.698302ms
I0303 06:21:52.282058 2232 replica.cpp:712] Persisted action at 0
I0303 06:21:52.282094 2232 replica.cpp:697] Replica learned NOP action at position 0
I0303 06:21:52.283459 2232 log.cpp:675] Writer started with ending position 0
I0303 06:21:52.285099 2232 leveldb.cpp:436] Reading position from leveldb took 72408ns
I0303 06:21:52.286762 2239 registrar.cpp:340] Successfully fetched the registry (0B) in 178.632192ms
I0303 06:21:52.286921 2239 registrar.cpp:439] Applied 1 operations in 44139ns; attempting to update the 'registry'
I0303 06:21:52.288328 2239 log.cpp:683] Attempting to append 170 bytes to the log
I0303 06:21:52.288599 2239 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0303 06:21:52.289860 2239 replica.cpp:537] Replica received write request for position 1 from (15035)@172.17.0.2:38514
I0303 06:21:52.315423 2239 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 25.49528ms
I0303 06:21:52.315518 2239 replica.cpp:712] Persisted action at 1
I0303 06:21:52.316614 2235 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0303 06:21:52.340529 2235 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 23.858668ms
I0303 06:21:52.340622 2235 replica.cpp:712] Persisted action at 1
I0303 06:21:52.340658 2235 replica.cpp:697] Replica learned APPEND action at position 1
I0303 06:21:52.342149 2238 registrar.cpp:484] Successfully updated the 'registry' in 55.14112ms
I0303 06:21:52.342314 2238 registrar.cpp:370] Successfully recovered registrar
I0303 06:21:52.342433 2235 log.cpp:702] Attempting to truncate the log to 1
I0303 06:21:52.342633 2235 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0303 06:21:52.342761 2238 master.cpp:1521] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0303 06:21:52.342964 2238 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0303 06:21:52.343739 2229 replica.cpp:537] Replica received write request for position 2 from (15036)@172.17.0.2:38514
I0303 06:21:52.365654 2229 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 21.847221ms
I0303 06:21:52.365751 2229 replica.cpp:712] Persisted action at 2
I0303 06:21:52.366928 2237 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0303 06:21:52.390794 2237 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 23.800052ms
I0303 06:21:52.390971 2237 leveldb.cpp:399] Deleting ~1 keys from leveldb took 88277ns
I0303 06:21:52.391000 2237 replica.cpp:712] Persisted action at 2
I0303 06:21:52.391038 2237 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0303 06:21:52.394477 2205 scheduler.cpp:172] Version: 0.28.0
I0303 06:21:52.395458 2228 scheduler.cpp:432] New master detected at master@172.17.0.2:38514
I0303 06:21:52.397651 2226 scheduler.cpp:332] Connected with the master at http://172.17.0.2:38514/master/api/v1/scheduler
I0303 06:21:52.399235 2226 scheduler.cpp:230] Sending SUBSCRIBE call to http://172.17.0.2:38514/master/api/v1/scheduler
I0303 06:21:52.401360 2226 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 06:21:52.401980 2226 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:43404
I0303 06:21:52.402484 2226 master.cpp:1973] Received subscription request for HTTP framework 'default'
I0303 06:21:52.402567 2226 master.cpp:1750] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0303 06:21:52.403372 2226 master.cpp:2064] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0303 06:21:52.404213 2226 hierarchical.cpp:265] Added framework d7e2d687-e074-48e0-9ead-e31d14d0cbca-0000
I0303 06:21:52.404328 2226 hierarchical.cpp:1453] No resources available to allocate!
I0303 06:21:52.404372 2226 hierarchical.cpp:1548] No inverse offers to send out!
I0303 06:21:52.404399 2226 hierarchical.cpp:1130] Performed allocation for 0 slaves in 149025ns
I0303 06:21:52.404428 2226 master.hpp:1657] Sending heartbeat to d7e2d687-e074-48e0-9ead-e31d14d0cbca-0000
I0303 06:21:52.405884 2236 scheduler.cpp:602] Enqueuing event SUBSCRIBED received from http://172.17.0.2:38514/master/api/v1/scheduler
I0303 06:21:52.406482 2236 scheduler.cpp:602] Enqueuing event HEARTBEAT received from http://172.17.0.2:38514/master/api/v1/scheduler
I0303 06:21:52.407557 2236 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0303 06:21:52.407781 2238 scheduler.cpp:230] Sending REQUEST call to http://172.17.0.2:38514/master/api/v1/scheduler
I0303 06:21:52.410437 2232 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 06:21:52.411036 2233 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:43405
I0303 06:21:52.411463 2233 master.cpp:2670] Processing REQUEST call for framework d7e2d687-e074-48e0-9ead-e31d14d0cbca-0000 (default)
I0303 06:21:52.411645 2225 hierarchical.cpp:589] Received resource request from framework d7e2d687-e074-48e0-9ead-e31d14d0cbca-0000
I0303 06:21:52.412416 2205 master.cpp:1026] Master terminating
I0303 06:21:52.412756 2238 hierarchical.cpp:326] Removed framework d7e2d687-e074-48e0-9ead-e31d14d0cbca-0000
E0303 06:21:52.413565 2237 scheduler.cpp:575] End-Of-File received from master. The master closed the event stream
I0303 06:21:52.415088 2236 scheduler.cpp:414] Re-detecting master
I0303 06:21:52.416589 2236 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 06:21:52.416748 2236 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 06:21:52.416921 2236 scheduler.cpp:432] New master detected at master@172.17.0.2:38514
I0303 06:21:52.426498 2231 scheduler.cpp:332] Connected with the master at http://172.17.0.2:38514/master/api/v1/scheduler
[ OK ] ContentType/SchedulerTest.Request/1 (526 ms)
[----------] 26 tests from ContentType/SchedulerTest (18754 ms total)
[----------] Global test environment tear-down
E0303 06:21:52.590443 2205 environment.cpp:752] Failed to remove '/tmp/LogZooKeeperTest_WriteRead_BRLa6M': No such file or directory
E0303 06:21:52.590649 2205 environment.cpp:752] Failed to remove '/tmp/LogZooKeeperTest_LostZooKeeper_6pIbjW': No such file or directory
[==========] 997 tests from 128 test cases ran. (776922 ms total)
[ PASSED ] 996 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] AppcImageFetcherTest.SimpleFetch
1 FAILED TEST
YOU HAVE 6 DISABLED TESTS
make[4]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[4]: *** [check-local] Error 1
make[3]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[3]: *** [check-am] Error 2
make[2]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[2]: *** [check] Error 2
make[1]: Leaving directory `/mesos/mesos-0.28.0/_build'
make[1]: *** [check-recursive] Error 1
make: *** [distcheck] Error 1
+ docker rmi mesos-1456983088-9206
Untagged: mesos-1456983088-9206:latest
Deleted: cc03767d7a2edd831e4b67c3a8f74650710cb5454065bfe3693b42ab6967025b
Deleted: c85cf20bd25fcef3fc6803265dfc53d5cbe5a461a3e44ceaed86f6d74a3ff99f
Deleted: 85faa401c04c0a79ff02158852b2423e2220c4cc6a9d14971adf8247f905b7de
Deleted: e110d17804548e172e8be5ca1c745ba65a422a297889b39ddf2cec5ec7b98185
Deleted: b850e03983d9798cc74422a73d4f09b23d7b8118f6dfb980f7b75528d2833ddd
Deleted: c5d3d0c98c5171b16ce73f0feae5c14e5dfb612bd1ec447ff8913e03ce1a70f1
Deleted: 5b29a63e3236ea7e59b8f68e092cc03a413e67915ca8ee50e89d78bb2a75a6bb
Deleted: 536c0641561298ca793dc0f0106c7dd75362e4842e088a8077218d2810eddae4
Deleted: ea1c36cc321a796ad5cc702a2ff16eed9bcf829ebd708526dd2bdf8fda75c7ee
Deleted: b6920b01c1c74fff6e674fc41800a42a56a0529a8dc18be33e5f09a69de3cdbc
Deleted: e41dffd0e31ef5f207bed230d1386a0633b91b00ae3635db21339a691f2ba477
Deleted: 2a18bf2479ff4a2d63b06a7ae2737ffec6e4c1d649e17f367b59f550a441be0a
Deleted: f66d59f13ff47f1828b84754915c39b9353f677b01bf6cb5c9d238127566374e
Deleted: a2adb8fd0c654b01c3b8095a03ab592683577afa5418f66ac4d6849a82b81602
Deleted: 6893570f589a9e6d3c6d6237ebba5638a083a7e896376c61ba4b1377bd4b507d
Deleted: 7753775b77a2787e9fa253ac24baaeb40a3475e2f32726f253f3bfe53ef26b20
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos » gcc,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(docker||Hadoop)&&(!ubuntu-us1) #1766
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)/1766/>
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(docker||Hadoop)&&(!ubuntu-us1) #1765
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)/1765/changes>
Changes:
[joris.van.remoortere] Fixed virtual function shadowing in appc provision test.
------------------------------------------
[...truncated 171527 lines...]
I0303 07:44:23.092772 2245 recover.cpp:447] Starting replica recovery
I0303 07:44:23.093096 2245 recover.cpp:473] Replica is in EMPTY status
I0303 07:44:23.094967 2245 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (15002)@172.17.0.2:37334
I0303 07:44:23.095352 2242 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0303 07:44:23.096690 2242 recover.cpp:564] Updating replica status to STARTING
I0303 07:44:23.101435 2241 master.cpp:375] Master b28e431c-a318-44cf-9b43-6b27f3023ba9 (9780ac8a6c5b) started on 172.17.0.2:37334
I0303 07:44:23.101481 2241 master.cpp:377] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/BwiApD/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="100secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/BwiApD/master" --zk_session_timeout="10secs"
I0303 07:44:23.101904 2241 master.cpp:424] Master allowing unauthenticated frameworks to register
I0303 07:44:23.101918 2241 master.cpp:427] Master only allowing authenticated slaves to register
I0303 07:44:23.101930 2241 credentials.hpp:35] Loading credentials for authentication from '/tmp/BwiApD/credentials'
I0303 07:44:23.102375 2241 master.cpp:467] Using default 'crammd5' authenticator
I0303 07:44:23.102561 2241 master.cpp:536] Using default 'basic' HTTP authenticator
I0303 07:44:23.102726 2241 master.cpp:570] Authorization enabled
I0303 07:44:23.104295 2245 whitelist_watcher.cpp:77] No whitelist given
I0303 07:44:23.105211 2236 hierarchical.cpp:144] Initialized hierarchical allocator process
I0303 07:44:23.105458 2232 master.cpp:1711] The newly elected leader is master@172.17.0.2:37334 with id b28e431c-a318-44cf-9b43-6b27f3023ba9
I0303 07:44:23.105489 2232 master.cpp:1724] Elected as the leading master!
I0303 07:44:23.105511 2232 master.cpp:1469] Recovering from registrar
I0303 07:44:23.105841 2232 registrar.cpp:307] Recovering registrar
I0303 07:44:23.133287 2240 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 36.271437ms
I0303 07:44:23.133378 2240 replica.cpp:320] Persisted replica status to STARTING
I0303 07:44:23.133780 2240 recover.cpp:473] Replica is in STARTING status
I0303 07:44:23.135907 2240 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (15005)@172.17.0.2:37334
I0303 07:44:23.136338 2240 recover.cpp:193] Received a recover response from a replica in STARTING status
I0303 07:44:23.137075 2240 recover.cpp:564] Updating replica status to VOTING
I0303 07:44:23.175073 2240 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 37.730805ms
I0303 07:44:23.175168 2240 replica.cpp:320] Persisted replica status to VOTING
I0303 07:44:23.175474 2240 recover.cpp:578] Successfully joined the Paxos group
I0303 07:44:23.175685 2240 recover.cpp:462] Recover process terminated
I0303 07:44:23.176537 2240 log.cpp:659] Attempting to start the writer
I0303 07:44:23.178625 2232 replica.cpp:493] Replica received implicit promise request from (15006)@172.17.0.2:37334 with proposal 1
I0303 07:44:23.216861 2232 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 38.160805ms
I0303 07:44:23.216951 2232 replica.cpp:342] Persisted promised to 1
I0303 07:44:23.218420 2232 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0303 07:44:23.220325 2232 replica.cpp:388] Replica received explicit promise request from (15007)@172.17.0.2:37334 for position 0 with proposal 2
I0303 07:44:23.258661 2232 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 38.267535ms
I0303 07:44:23.258754 2232 replica.cpp:712] Persisted action at 0
I0303 07:44:23.260725 2232 replica.cpp:537] Replica received write request for position 0 from (15008)@172.17.0.2:37334
I0303 07:44:23.260828 2232 leveldb.cpp:436] Reading position from leveldb took 51532ns
I0303 07:44:23.300426 2232 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 39.53307ms
I0303 07:44:23.300518 2232 replica.cpp:712] Persisted action at 0
I0303 07:44:23.301668 2243 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0303 07:44:23.342226 2243 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.489737ms
I0303 07:44:23.342321 2243 replica.cpp:712] Persisted action at 0
I0303 07:44:23.342362 2243 replica.cpp:697] Replica learned NOP action at position 0
I0303 07:44:23.343735 2243 log.cpp:675] Writer started with ending position 0
I0303 07:44:23.345394 2243 leveldb.cpp:436] Reading position from leveldb took 76982ns
I0303 07:44:23.351883 2244 registrar.cpp:340] Successfully fetched the registry (0B) in 245.94816ms
I0303 07:44:23.352094 2244 registrar.cpp:439] Applied 1 operations in 47304ns; attempting to update the 'registry'
I0303 07:44:23.353054 2236 log.cpp:683] Attempting to append 170 bytes to the log
I0303 07:44:23.353277 2244 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0303 07:44:23.354364 2236 replica.cpp:537] Replica received write request for position 1 from (15009)@172.17.0.2:37334
I0303 07:44:23.390924 2236 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 36.48423ms
I0303 07:44:23.391021 2236 replica.cpp:712] Persisted action at 1
I0303 07:44:23.392026 2235 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0303 07:44:23.424398 2235 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 32.312148ms
I0303 07:44:23.424499 2235 replica.cpp:712] Persisted action at 1
I0303 07:44:23.424535 2235 replica.cpp:697] Replica learned APPEND action at position 1
I0303 07:44:23.426352 2239 registrar.cpp:484] Successfully updated the 'registry' in 74.168064ms
I0303 07:44:23.426578 2239 registrar.cpp:370] Successfully recovered registrar
I0303 07:44:23.426616 2235 log.cpp:702] Attempting to truncate the log to 1
I0303 07:44:23.426882 2239 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0303 07:44:23.427294 2235 master.cpp:1521] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0303 07:44:23.427537 2241 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0303 07:44:23.428702 2240 replica.cpp:537] Replica received write request for position 2 from (15010)@172.17.0.2:37334
I0303 07:44:23.449523 2240 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 20.746305ms
I0303 07:44:23.449625 2240 replica.cpp:712] Persisted action at 2
I0303 07:44:23.451346 2240 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0303 07:44:23.474653 2240 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 23.248361ms
I0303 07:44:23.474829 2240 leveldb.cpp:399] Deleting ~1 keys from leveldb took 88131ns
I0303 07:44:23.474859 2240 replica.cpp:712] Persisted action at 2
I0303 07:44:23.474900 2240 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0303 07:44:23.479152 2212 scheduler.cpp:172] Version: 0.28.0
I0303 07:44:23.480423 2240 scheduler.cpp:432] New master detected at master@172.17.0.2:37334
I0303 07:44:23.483296 2233 scheduler.cpp:332] Connected with the master at http://172.17.0.2:37334/master/api/v1/scheduler
I0303 07:44:23.485107 2238 scheduler.cpp:230] Sending SUBSCRIBE call to http://172.17.0.2:37334/master/api/v1/scheduler
I0303 07:44:23.486526 2239 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 07:44:23.487038 2239 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:39334
I0303 07:44:23.487295 2239 master.cpp:1973] Received subscription request for HTTP framework 'default'
I0303 07:44:23.487363 2239 master.cpp:1750] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0303 07:44:23.487887 2239 master.cpp:2064] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0303 07:44:23.488378 2233 hierarchical.cpp:265] Added framework b28e431c-a318-44cf-9b43-6b27f3023ba9-0000
I0303 07:44:23.488469 2233 hierarchical.cpp:1453] No resources available to allocate!
I0303 07:44:23.488510 2233 hierarchical.cpp:1548] No inverse offers to send out!
I0303 07:44:23.488520 2239 master.hpp:1657] Sending heartbeat to b28e431c-a318-44cf-9b43-6b27f3023ba9-0000
I0303 07:44:23.488540 2233 hierarchical.cpp:1130] Performed allocation for 0 slaves in 139890ns
I0303 07:44:23.490289 2239 scheduler.cpp:602] Enqueuing event SUBSCRIBED received from http://172.17.0.2:37334/master/api/v1/scheduler
I0303 07:44:23.491186 2239 scheduler.cpp:602] Enqueuing event HEARTBEAT received from http://172.17.0.2:37334/master/api/v1/scheduler
I0303 07:44:23.491865 2239 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0303 07:44:23.492677 2238 scheduler.cpp:230] Sending REQUEST call to http://172.17.0.2:37334/master/api/v1/scheduler
I0303 07:44:23.494542 2244 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 07:44:23.495086 2244 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:39335
I0303 07:44:23.495252 2244 master.cpp:2670] Processing REQUEST call for framework b28e431c-a318-44cf-9b43-6b27f3023ba9-0000 (default)
I0303 07:44:23.495510 2244 hierarchical.cpp:589] Received resource request from framework b28e431c-a318-44cf-9b43-6b27f3023ba9-0000
I0303 07:44:23.497606 2237 master.cpp:1026] Master terminating
I0303 07:44:23.497941 2241 hierarchical.cpp:326] Removed framework b28e431c-a318-44cf-9b43-6b27f3023ba9-0000
E0303 07:44:23.508319 2233 scheduler.cpp:575] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (602 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0303 07:44:23.639055 2212 leveldb.cpp:174] Opened db in 113.380963ms
I0303 07:44:23.676064 2212 leveldb.cpp:181] Compacted db in 36.922015ms
I0303 07:44:23.676170 2212 leveldb.cpp:196] Created db iterator in 31322ns
I0303 07:44:23.676190 2212 leveldb.cpp:202] Seeked to beginning of db in 3792ns
I0303 07:44:23.676203 2212 leveldb.cpp:271] Iterated through 0 keys in the db in 345ns
I0303 07:44:23.676273 2212 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0303 07:44:23.677099 2233 recover.cpp:447] Starting replica recovery
I0303 07:44:23.677655 2233 recover.cpp:473] Replica is in EMPTY status
I0303 07:44:23.678671 2245 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (15018)@172.17.0.2:37334
I0303 07:44:23.679177 2238 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0303 07:44:23.679683 2232 recover.cpp:564] Updating replica status to STARTING
I0303 07:44:23.680990 2238 master.cpp:375] Master 9e0dd336-ba69-4627-bd93-e7f99c723ea5 (9780ac8a6c5b) started on 172.17.0.2:37334
I0303 07:44:23.681015 2238 master.cpp:377] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/nE1NHP/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="100secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/nE1NHP/master" --zk_session_timeout="10secs"
I0303 07:44:23.681355 2238 master.cpp:424] Master allowing unauthenticated frameworks to register
I0303 07:44:23.681370 2238 master.cpp:427] Master only allowing authenticated slaves to register
I0303 07:44:23.681380 2238 credentials.hpp:35] Loading credentials for authentication from '/tmp/nE1NHP/credentials'
I0303 07:44:23.681664 2238 master.cpp:467] Using default 'crammd5' authenticator
I0303 07:44:23.681828 2238 master.cpp:536] Using default 'basic' HTTP authenticator
I0303 07:44:23.681987 2238 master.cpp:570] Authorization enabled
I0303 07:44:23.682168 2234 hierarchical.cpp:144] Initialized hierarchical allocator process
I0303 07:44:23.682173 2242 whitelist_watcher.cpp:77] No whitelist given
I0303 07:44:23.684149 2234 master.cpp:1711] The newly elected leader is master@172.17.0.2:37334 with id 9e0dd336-ba69-4627-bd93-e7f99c723ea5
I0303 07:44:23.684190 2234 master.cpp:1724] Elected as the leading master!
I0303 07:44:23.684214 2234 master.cpp:1469] Recovering from registrar
I0303 07:44:23.684540 2234 registrar.cpp:307] Recovering registrar
I0303 07:44:23.709323 2232 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 29.414687ms
I0303 07:44:23.709419 2232 replica.cpp:320] Persisted replica status to STARTING
I0303 07:44:23.709743 2236 recover.cpp:473] Replica is in STARTING status
I0303 07:44:23.711024 2245 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (15020)@172.17.0.2:37334
I0303 07:44:23.711535 2231 recover.cpp:193] Received a recover response from a replica in STARTING status
I0303 07:44:23.712033 2234 recover.cpp:564] Updating replica status to VOTING
I0303 07:44:23.726091 2236 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 13.845093ms
I0303 07:44:23.726186 2236 replica.cpp:320] Persisted replica status to VOTING
I0303 07:44:23.726454 2241 recover.cpp:578] Successfully joined the Paxos group
I0303 07:44:23.726752 2241 recover.cpp:462] Recover process terminated
I0303 07:44:23.727335 2241 log.cpp:659] Attempting to start the writer
I0303 07:44:23.728700 2234 replica.cpp:493] Replica received implicit promise request from (15021)@172.17.0.2:37334 with proposal 1
I0303 07:44:23.742863 2234 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 14.100485ms
I0303 07:44:23.742952 2234 replica.cpp:342] Persisted promised to 1
I0303 07:44:23.743845 2240 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0303 07:44:23.745050 2231 replica.cpp:388] Replica received explicit promise request from (15022)@172.17.0.2:37334 for position 0 with proposal 2
I0303 07:44:23.759642 2231 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 14.520716ms
I0303 07:44:23.759734 2231 replica.cpp:712] Persisted action at 0
I0303 07:44:23.761065 2244 replica.cpp:537] Replica received write request for position 0 from (15023)@172.17.0.2:37334
I0303 07:44:23.761153 2244 leveldb.cpp:436] Reading position from leveldb took 44621ns
I0303 07:44:23.776424 2244 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 15.198492ms
I0303 07:44:23.776515 2244 replica.cpp:712] Persisted action at 0
I0303 07:44:23.777184 2238 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0303 07:44:23.793270 2238 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 16.029767ms
I0303 07:44:23.793366 2238 replica.cpp:712] Persisted action at 0
I0303 07:44:23.793402 2238 replica.cpp:697] Replica learned NOP action at position 0
I0303 07:44:23.794312 2238 log.cpp:675] Writer started with ending position 0
I0303 07:44:23.795634 2241 leveldb.cpp:436] Reading position from leveldb took 63280ns
I0303 07:44:23.797004 2241 registrar.cpp:340] Successfully fetched the registry (0B) in 112.417024ms
I0303 07:44:23.797144 2241 registrar.cpp:439] Applied 1 operations in 39586ns; attempting to update the 'registry'
I0303 07:44:23.798529 2241 log.cpp:683] Attempting to append 170 bytes to the log
I0303 07:44:23.798774 2241 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0303 07:44:23.799823 2239 replica.cpp:537] Replica received write request for position 1 from (15024)@172.17.0.2:37334
I0303 07:44:23.818372 2239 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 18.482146ms
I0303 07:44:23.818459 2239 replica.cpp:712] Persisted action at 1
I0303 07:44:23.819417 2231 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0303 07:44:23.835145 2231 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 15.675755ms
I0303 07:44:23.835243 2231 replica.cpp:712] Persisted action at 1
I0303 07:44:23.835279 2231 replica.cpp:697] Replica learned APPEND action at position 1
I0303 07:44:23.836691 2244 registrar.cpp:484] Successfully updated the 'registry' in 39.475968ms
I0303 07:44:23.836872 2244 registrar.cpp:370] Successfully recovered registrar
I0303 07:44:23.836983 2246 log.cpp:702] Attempting to truncate the log to 1
I0303 07:44:23.837127 2236 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0303 07:44:23.837414 2231 master.cpp:1521] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0303 07:44:23.837647 2239 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0303 07:44:23.838181 2232 replica.cpp:537] Replica received write request for position 2 from (15025)@172.17.0.2:37334
I0303 07:44:23.851909 2232 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 13.664021ms
I0303 07:44:23.852007 2232 replica.cpp:712] Persisted action at 2
I0303 07:44:23.852982 2239 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0303 07:44:23.868692 2239 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 15.655122ms
I0303 07:44:23.868844 2239 leveldb.cpp:399] Deleting ~1 keys from leveldb took 66269ns
I0303 07:44:23.868871 2239 replica.cpp:712] Persisted action at 2
I0303 07:44:23.868907 2239 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0303 07:44:23.879292 2212 scheduler.cpp:172] Version: 0.28.0
I0303 07:44:23.880095 2243 scheduler.cpp:432] New master detected at master@172.17.0.2:37334
I0303 07:44:23.882050 2234 scheduler.cpp:332] Connected with the master at http://172.17.0.2:37334/master/api/v1/scheduler
I0303 07:44:23.883375 2238 scheduler.cpp:230] Sending SUBSCRIBE call to http://172.17.0.2:37334/master/api/v1/scheduler
I0303 07:44:23.884970 2239 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 07:44:23.885488 2239 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:39344
I0303 07:44:23.885931 2239 master.cpp:1973] Received subscription request for HTTP framework 'default'
I0303 07:44:23.886010 2239 master.cpp:1750] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0303 07:44:23.886308 2239 master.cpp:2064] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0303 07:44:23.886793 2245 hierarchical.cpp:265] Added framework 9e0dd336-ba69-4627-bd93-e7f99c723ea5-0000
I0303 07:44:23.886894 2245 hierarchical.cpp:1453] No resources available to allocate!
I0303 07:44:23.886941 2245 hierarchical.cpp:1548] No inverse offers to send out!
I0303 07:44:23.886975 2245 hierarchical.cpp:1130] Performed allocation for 0 slaves in 151925ns
I0303 07:44:23.887006 2245 master.hpp:1657] Sending heartbeat to 9e0dd336-ba69-4627-bd93-e7f99c723ea5-0000
I0303 07:44:23.888928 2245 scheduler.cpp:602] Enqueuing event SUBSCRIBED received from http://172.17.0.2:37334/master/api/v1/scheduler
I0303 07:44:23.890202 2242 scheduler.cpp:602] Enqueuing event HEARTBEAT received from http://172.17.0.2:37334/master/api/v1/scheduler
I0303 07:44:23.890534 2242 scheduler.cpp:230] Sending REQUEST call to http://172.17.0.2:37334/master/api/v1/scheduler
I0303 07:44:23.891275 2242 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0303 07:44:23.891960 2241 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 07:44:23.892447 2241 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:39345
I0303 07:44:23.892787 2241 master.cpp:2670] Processing REQUEST call for framework 9e0dd336-ba69-4627-bd93-e7f99c723ea5-0000 (default)
I0303 07:44:23.892946 2245 hierarchical.cpp:589] Received resource request from framework 9e0dd336-ba69-4627-bd93-e7f99c723ea5-0000
I0303 07:44:23.894096 2212 master.cpp:1026] Master terminating
I0303 07:44:23.894737 2245 hierarchical.cpp:326] Removed framework 9e0dd336-ba69-4627-bd93-e7f99c723ea5-0000
E0303 07:44:23.896391 2238 scheduler.cpp:575] End-Of-File received from master. The master closed the event stream
I0303 07:44:23.897883 2234 scheduler.cpp:414] Re-detecting master
I0303 07:44:23.898341 2234 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 07:44:23.898473 2234 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 07:44:23.898773 2236 scheduler.cpp:432] New master detected at master@172.17.0.2:37334
I0303 07:44:23.901794 2235 scheduler.cpp:332] Connected with the master at http://172.17.0.2:37334/master/api/v1/scheduler
[ OK ] ContentType/SchedulerTest.Request/1 (392 ms)
[----------] 26 tests from ContentType/SchedulerTest (21354 ms total)
[----------] Global test environment tear-down
E0303 07:44:24.072099 2212 environment.cpp:752] Failed to remove '/tmp/LogZooKeeperTest_WriteRead_AJjE4A': No such file or directory
E0303 07:44:24.072326 2212 environment.cpp:752] Failed to remove '/tmp/LogZooKeeperTest_LostZooKeeper_bkWLse': No such file or directory
[==========] 997 tests from 128 test cases ran. (866418 ms total)
[ PASSED ] 996 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] AppcImageFetcherTest.SimpleFetch
1 FAILED TEST
YOU HAVE 6 DISABLED TESTS
make[4]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[4]: *** [check-local] Error 1
make[3]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[3]: *** [check-am] Error 2
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[1]: Leaving directory `/mesos/mesos-0.28.0/_build'
make[1]: *** [check-recursive] Error 1
make: *** [distcheck] Error 1
+ docker rmi mesos-1456987288-30661
Untagged: mesos-1456987288-30661:latest
Deleted: 093660c93fe7f7eb0869f1644c99d6ac0e114d6e278606955d245350d464e97b
Deleted: ac7c650c51330e7accae41042de09a7aac5227392d06d9e9b680e6826cbb2710
Deleted: 82cedd8825010dce8b8839d67c483e76e962c563e7c43d534e98bf217ca4939e
Deleted: f3d23146ad2489798b9a667a59d91d0645591a05ee33f7a3f31f84f5427364cd
Deleted: 43d077d41791445d3b9b137cc993b413abe259ab5f069c3e96c7dc0535a4f184
Deleted: dab78171dc58a4f07defc0a274079b5c7db398512ce84fabdd1604c045ff7455
Deleted: 8e244dbb82d46206de76a1d03d81632eb7c5ce4fdf8880d5b9eba38b68bc0777
Deleted: 3439aeef9d300b464fbe7551ab151658119fedaffaaeca446a7984dc47860040
Deleted: 08ff315d5c077dddc8b962e0e3b34027fc2029acb12ed362ab31b38420689f49
Deleted: 347354d36f31afb35da6629a42772040dcd4758ef602d851aaac2b76932af948
Deleted: 5ec42c9eb8f6cf6fe82ca6cc5b4c628f5f6b3fe7af562910db06c72555beac94
Deleted: a003dff711c72114bc3b53693c48773c6b86d1198382ec79c99f7f0492e92722
Deleted: 429ed22a8639fe89953d2ca4a96e20fe473b83ab0b1604b6d6dd88afe9d4c145
Deleted: 1c8210962c966fc820490869a3c907c2f8477e838e79e87837834f674ce5d388
Deleted: bacfee3b1d67d4326635d413eff5e366c53cd817dabe1a1e97e2cde1176f03a4
Deleted: 22847fdf1c5ca9352adf838ebd4d6c3d609d69b21345e1b1eb88702356dd255d
Build step 'Execute shell' marked build as failure