Mailing-List: contact builds-help@mesos.apache.org; run by ezmlm
Precedence: bulk
Reply-To: builds@mesos.apache.org
Date: Tue, 15 Aug 2017 04:13:58 +0000 (UTC)
From: Apache Jenkins Server  <jenkins@builds.apache.org>
To: builds@mesos.apache.org
Message-ID: <1405985416.2900.1502770438085.JavaMail.jenkins@jenkins-master>
In-Reply-To: <1229311731.2876.1502763301989.JavaMail.jenkins@jenkins-master>
References: <1229311731.2876.1502763301989.JavaMail.jenkins@jenkins-master>
Subject: Build failed in Jenkins: Mesos-Reviewbot #18873
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: quoted-printable
archived-at: Tue, 15 Aug 2017 04:14:08 -0000

See <https://builds.apache.org/job/Mesos-Reviewbot/18873/display/redirect>

------------------------------------------
[...truncated 25.55 MB...]
I0815 04:13:48.968981  5274 http.cpp:673] Processing call GET_AGENTS
I0815 04:13:48.976833  5276 slave.cpp:843] Agent terminating
I0815 04:13:48.977126  5278 master.cpp:1318] Agent 64a1c331-2155-4a2f-b33d-=
cb6134e83100-S0 at slave(623)@172.17.0.2:34041 (1249dfeb6dc6) disconnected
I0815 04:13:48.977183  5278 master.cpp:3301] Disconnecting agent 64a1c331-2=
155-4a2f-b33d-cb6134e83100-S0 at slave(623)@172.17.0.2:34041 (1249dfeb6dc6)
I0815 04:13:48.977309  5278 master.cpp:3320] Deactivating agent 64a1c331-21=
55-4a2f-b33d-cb6134e83100-S0 at slave(623)@172.17.0.2:34041 (1249dfeb6dc6)
I0815 04:13:48.977555  5275 hierarchical.cpp:690] Agent 64a1c331-2155-4a2f-=
b33d-cb6134e83100-S0 deactivated
I0815 04:13:48.994863  5253 master.cpp:1160] Master terminating
I0815 04:13:48.997246  5274 hierarchical.cpp:626] Removed agent 64a1c331-21=
55-4a2f-b33d-cb6134e83100-S0
[       OK ] ContentType/MasterAPITest.GetRecoveredAgents/0 (369 ms)
[ RUN      ] ContentType/MasterAPITest.GetRecoveredAgents/1
I0815 04:13:49.008806  5253 cluster.cpp:162] Creating default 'local' autho=
rizer
I0815 04:13:49.017894  5253 leveldb.cpp:174] Opened db in 8.446571ms
I0815 04:13:49.020591  5253 leveldb.cpp:181] Compacted db in 2.628546ms
I0815 04:13:49.020683  5253 leveldb.cpp:196] Created db iterator in 27760ns
I0815 04:13:49.020776  5253 leveldb.cpp:202] Seeked to beginning of db in 3=
037ns
I0815 04:13:49.020880  5253 leveldb.cpp:271] Iterated through 0 keys in the=
 db in 611ns
I0815 04:13:49.020936  5253 replica.cpp:779] Replica recovered with log pos=
itions 0 -> 0 with 1 holes and 0 unlearned
I0815 04:13:49.022050  5279 recover.cpp:451] Starting replica recovery
I0815 04:13:49.022410  5279 recover.cpp:477] Replica is in EMPTY status
I0815 04:13:49.024066  5279 replica.cpp:676] Replica in EMPTY status receiv=
ed a broadcasted recover request from __req_res__(1723)@172.17.0.2:34041
I0815 04:13:49.024642  5277 recover.cpp:197] Received a recover response fr=
om a replica in EMPTY status
I0815 04:13:49.025343  5276 recover.cpp:568] Updating replica status to STA=
RTING
I0815 04:13:49.027860  5278 leveldb.cpp:304] Persisting metadata (8 bytes) =
to leveldb took 2.326093ms
I0815 04:13:49.027925  5278 replica.cpp:322] Persisted replica status to ST=
ARTING
I0815 04:13:49.028393  5279 recover.cpp:477] Replica is in STARTING status
I0815 04:13:49.029369  5278 master.cpp:442] Master 6af4388b-cfda-4a01-8ce0-=
63d30f8e02c1 (1249dfeb6dc6) started on 172.17.0.2:34041
I0815 04:13:49.029404  5278 master.cpp:444] Flags at startup: --acls=3D"vie=
w_roles {
  principals {
    values: "test-principal"
  }
  roles {
    type: ANY
  }
}
" --agent_ping_timeout=3D"15secs" --agent_reregister_timeout=3D"10mins" --a=
llocation_interval=3D"1secs" --allocator=3D"HierarchicalDRF" --authenticate=
_agents=3D"true" --authenticate_frameworks=3D"true" --authenticate_http_fra=
meworks=3D"true" --authenticate_http_readonly=3D"true" --authenticate_http_=
readwrite=3D"true" --authenticators=3D"crammd5" --authorizers=3D"local" --c=
redentials=3D"/tmp/aImZSv/credentials" --filter_gpu_resources=3D"true" --fr=
amework_sorter=3D"drf" --help=3D"false" --hostname_lookup=3D"true" --http_a=
uthenticators=3D"basic" --http_framework_authenticators=3D"basic" --initial=
ize_driver_logging=3D"true" --log_auto_initialize=3D"true" --logbufsecs=3D"=
0" --logging_level=3D"INFO" --max_agent_ping_timeouts=3D"5" --max_completed=
_frameworks=3D"50" --max_completed_tasks_per_framework=3D"1000" --max_unrea=
chable_tasks_per_framework=3D"1000" --port=3D"5050" --quiet=3D"false" --rec=
overy_agent_removal_limit=3D"100%" --registry=3D"replicated_log" --registry=
_fetch_timeout=3D"1mins" --registry_gc_interval=3D"15mins" --registry_max_a=
gent_age=3D"2weeks" --registry_max_agent_count=3D"102400" --registry_store_=
timeout=3D"100secs" --registry_strict=3D"false" --root_submissions=3D"true"=
 --user_sorter=3D"drf" --version=3D"false" --webui_dir=3D"/mesos/mesos-1.4.=
0/_inst/share/mesos/webui" --work_dir=3D"/tmp/aImZSv/master" --zk_session_t=
imeout=3D"10secs"
I0815 04:13:49.030156  5278 master.cpp:494] Master only allowing authentica=
ted frameworks to register
I0815 04:13:49.030179  5278 master.cpp:508] Master only allowing authentica=
ted agents to register
I0815 04:13:49.030228  5278 master.cpp:521] Master only allowing authentica=
ted HTTP frameworks to register
I0815 04:13:49.030247  5278 credentials.hpp:37] Loading credentials for aut=
hentication from '/tmp/aImZSv/credentials'
I0815 04:13:49.030781  5278 master.cpp:566] Using default 'crammd5' authent=
icator
I0815 04:13:49.031113  5278 http.cpp:1026] Creating default 'basic' HTTP au=
thenticator for realm 'mesos-master-readonly'
I0815 04:13:49.031234  5273 replica.cpp:676] Replica in STARTING status rec=
eived a broadcasted recover request from __req_res__(1724)@172.17.0.2:34041
I0815 04:13:49.031491  5278 http.cpp:1026] Creating default 'basic' HTTP au=
thenticator for realm 'mesos-master-readwrite'
I0815 04:13:49.031891  5278 http.cpp:1026] Creating default 'basic' HTTP au=
thenticator for realm 'mesos-master-scheduler'
I0815 04:13:49.032152  5278 master.cpp:646] Authorization enabled
I0815 04:13:49.032450  5276 hierarchical.cpp:171] Initialized hierarchical =
allocator process
I0815 04:13:49.032606  5276 whitelist_watcher.cpp:77] No whitelist given
I0815 04:13:49.033149  5275 recover.cpp:197] Received a recover response fr=
om a replica in STARTING status
I0815 04:13:49.034180  5273 recover.cpp:568] Updating replica status to VOT=
ING
I0815 04:13:49.036231  5276 leveldb.cpp:304] Persisting metadata (8 bytes) =
to leveldb took 1.792459ms
I0815 04:13:49.036294  5276 replica.cpp:322] Persisted replica status to VO=
TING
I0815 04:13:49.036978  5276 recover.cpp:582] Successfully joined the Paxos =
group
I0815 04:13:49.037210  5276 recover.cpp:466] Recover process terminated
I0815 04:13:49.037693  5279 master.cpp:2163] Elected as the leading master!
I0815 04:13:49.037747  5279 master.cpp:1702] Recovering from registrar
I0815 04:13:49.038110  5273 registrar.cpp:347] Recovering registrar
I0815 04:13:49.038952  5276 log.cpp:536] Attempting to start the writer
I0815 04:13:49.040650  5276 replica.cpp:496] Replica received implicit prom=
ise request from __req_res__(1725)@172.17.0.2:34041 with proposal 1
I0815 04:13:49.042582  5276 leveldb.cpp:304] Persisting metadata (8 bytes) =
to leveldb took 1.867287ms
I0815 04:13:49.042631  5276 replica.cpp:344] Persisted promised to 1
I0815 04:13:49.043613  5272 coordinator.cpp:238] Coordinator attempting to =
fill missing positions
I0815 04:13:49.045629  5273 replica.cpp:391] Replica received explicit prom=
ise request from __req_res__(1726)@172.17.0.2:34041 for position 0 with pro=
posal 2
I0815 04:13:49.047579  5273 leveldb.cpp:341] Persisting action (8 bytes) to=
 leveldb took 1.822354ms
I0815 04:13:49.047680  5273 replica.cpp:711] Persisted action NOP at positi=
on 0
I0815 04:13:49.049448  5277 replica.cpp:540] Replica received write request=
 for position 0 from __req_res__(1727)@172.17.0.2:34041
I0815 04:13:49.049562  5277 leveldb.cpp:436] Reading position from leveldb =
took 49806ns
I0815 04:13:49.051545  5277 leveldb.cpp:341] Persisting action (14 bytes) t=
o leveldb took 1.924882ms
I0815 04:13:49.051594  5277 replica.cpp:711] Persisted action NOP at positi=
on 0
I0815 04:13:49.052484  5277 replica.cpp:694] Replica received learned notic=
e for position 0 from log-network(98)@172.17.0.2:34041
I0815 04:13:49.054793  5277 leveldb.cpp:341] Persisting action (16 bytes) t=
o leveldb took 2.250062ms
I0815 04:13:49.054860  5277 replica.cpp:711] Persisted action NOP at positi=
on 0
I0815 04:13:49.055799  5275 log.cpp:552] Writer started with ending positio=
n 0
I0815 04:13:49.057586  5274 leveldb.cpp:436] Reading position from leveldb =
took 66989ns
I0815 04:13:49.058897  5278 registrar.cpp:391] Successfully fetched the reg=
istry (0B) in 20.679168ms
I0815 04:13:49.059123  5278 registrar.cpp:495] Applied 1 operations in 3798=
6ns; attempting to update the registry
I0815 04:13:49.060070  5279 log.cpp:560] Attempting to append 168 bytes to =
the log
I0815 04:13:49.060636  5279 coordinator.cpp:348] Coordinator attempting to =
write APPEND action at position 1
I0815 04:13:49.062113  5274 replica.cpp:540] Replica received write request=
 for position 1 from __req_res__(1728)@172.17.0.2:34041
I0815 04:13:49.064270  5274 leveldb.cpp:341] Persisting action (187 bytes) =
to leveldb took 2.082078ms
I0815 04:13:49.064328  5274 replica.cpp:711] Persisted action APPEND at pos=
ition 1
I0815 04:13:49.065315  5273 replica.cpp:694] Replica received learned notic=
e for position 1 from log-network(98)@172.17.0.2:34041
I0815 04:13:49.067111  5273 leveldb.cpp:341] Persisting action (189 bytes) =
to leveldb took 1.685428ms
I0815 04:13:49.067210  5273 replica.cpp:711] Persisted action APPEND at pos=
ition 1
I0815 04:13:49.068811  5278 registrar.cpp:552] Successfully updated the reg=
istry in 9.587968ms
I0815 04:13:49.068987  5279 log.cpp:579] Attempting to truncate the log to =
1
I0815 04:13:49.069133  5278 registrar.cpp:424] Successfully recovered regis=
trar
I0815 04:13:49.069546  5273 coordinator.cpp:348] Coordinator attempting to =
write TRUNCATE action at position 2
I0815 04:13:49.069872  5277 master.cpp:1801] Recovered 0 agents from the re=
gistry (129B); allowing 10mins for agents to re-register
I0815 04:13:49.070179  5275 hierarchical.cpp:209] Skipping recovery of hier=
archical allocator: nothing to recover
I0815 04:13:49.071323  5276 replica.cpp:540] Replica received write request=
 for position 2 from __req_res__(1729)@172.17.0.2:34041
I0815 04:13:49.073189  5276 leveldb.cpp:341] Persisting action (16 bytes) t=
o leveldb took 1.791185ms
I0815 04:13:49.073243  5276 replica.cpp:711] Persisted action TRUNCATE at p=
osition 2
I0815 04:13:49.074548  5273 replica.cpp:694] Replica received learned notic=
e for position 2 from log-network(98)@172.17.0.2:34041
I0815 04:13:49.076483  5273 leveldb.cpp:341] Persisting action (18 bytes) t=
o leveldb took 1.818574ms
I0815 04:13:49.076866  5273 leveldb.cpp:399] Deleting ~1 keys from leveldb =
took 289239ns
I0815 04:13:49.076938  5273 replica.cpp:711] Persisted action TRUNCATE at p=
osition 2
I0815 04:13:49.086094  5253 process.cpp:3228] Attempting to spawn already s=
pawned process files@172.17.0.2:34041
I0815 04:13:49.087728  5253 containerizer.cpp:246] Using isolation: posix/c=
pu,posix/mem,filesystem/posix,network/cni,environment_secret
W0815 04:13:49.088548  5253 backend.cpp:76] Failed to create 'overlay' back=
end: OverlayBackend requires root privileges
W0815 04:13:49.088773  5253 backend.cpp:76] Failed to create 'bind' backend=
: BindBackend requires root privileges
I0815 04:13:49.088816  5253 provisioner.cpp:255] Using default backend 'cop=
y'
I0815 04:13:49.091749  5253 cluster.cpp:448] Creating default 'local' autho=
rizer
I0815 04:13:49.094789  5277 slave.cpp:250] Mesos agent started on (624)@172=
.17.0.2:34041
I0815 04:13:49.094832  5277 slave.cpp:251] Flags at startup: --acls=3D"" --=
appc_simple_discovery_uri_prefix=3D"http://" --appc_store_dir=3D"/tmp/Conte=
ntType_MasterAPITest_GetRecoveredAgents_1_IKVhiq/store/appc" --authenticate=
_http_readonly=3D"true" --authenticate_http_readwrite=3D"true" --authentica=
tee=3D"crammd5" --authentication_backoff_factor=3D"1secs" --authorizer=3D"l=
ocal" --cgroups_cpu_enable_pids_and_tids_count=3D"false" --cgroups_enable_c=
fs=3D"false" --cgroups_hierarchy=3D"/sys/fs/cgroup" --cgroups_limit_swap=3D=
"false" --cgroups_root=3D"mesos" --container_disk_watch_interval=3D"15secs"=
 --containerizers=3D"mesos" --credential=3D"/tmp/ContentType_MasterAPITest_=
GetRecoveredAgents_1_IKVhiq/credential" --default_role=3D"*" --disk_watch_i=
nterval=3D"1mins" --docker=3D"docker" --docker_kill_orphans=3D"true" --dock=
er_registry=3D"https://registry-1.docker.io" --docker_remove_delay=3D"6hrs"=
 --docker_socket=3D"/var/run/docker.sock" --docker_stop_timeout=3D"0ns" --d=
ocker_store_dir=3D"/tmp/ContentType_MasterAPITest_GetRecoveredAgents_1_IKVh=
iq/store/docker" --docker_volume_checkpoint_dir=3D"/var/run/mesos/isolators=
/docker/volume" --enforce_container_disk_quota=3D"false" --executor_registr=
ation_timeout=3D"1mins" --executor_reregistration_timeout=3D"2secs" --execu=
tor_shutdown_grace_period=3D"5secs" --fetcher_cache_dir=3D"/tmp/ContentType=
_MasterAPITest_GetRecoveredAgents_1_IKVhiq/fetch" --fetcher_cache_size=3D"2=
GB" --frameworks_home=3D"" --gc_delay=3D"1weeks" --gc_disk_headroom=3D"0.1"=
 --hadoop_home=3D"" --help=3D"false" --hostname_lookup=3D"true" --http_comm=
and_executor=3D"false" --http_credentials=3D"/tmp/ContentType_MasterAPITest=
_GetRecoveredAgents_1_IKVhiq/http_credentials" --http_heartbeat_interval=3D=
"30secs" --initialize_driver_logging=3D"true" --isolation=3D"posix/cpu,posi=
x/mem" --launcher=3D"posix" --launcher_dir=3D"/mesos/mesos-1.4.0/_build/src=
" --logbufsecs=3D"0" --logging_level=3D"INFO" --max_completed_executors_per=
_framework=3D"150" --oversubscribed_resources_interval=3D"15secs" --perf_du=
ration=3D"10secs" --perf_interval=3D"1mins" --port=3D"5051" --qos_correctio=
n_interval_min=3D"0ns" --quiet=3D"false" --recover=3D"reconnect" --recovery=
_timeout=3D"15mins" --registration_backoff_factor=3D"10ms" --resources=3D"c=
pus(foo):1;cpus(*):2;gpus(*):0;mem(foo):1024;mem(*):1024;disk(foo):1024;dis=
k(*):1024;ports(*):[31000-32000]" --revocable_cpu_low_priority=3D"true" --r=
untime_dir=3D"/tmp/ContentType_MasterAPITest_GetRecoveredAgents_1_IKVhiq" -=
-sandbox_directory=3D"/mnt/mesos/sandbox" --strict=3D"true" --switch_user=
=3D"true" --systemd_enable_support=3D"true" --systemd_runtime_directory=3D"=
/run/systemd/system" --version=3D"false" --work_dir=3D"/tmp/ContentType_Mas=
terAPITest_GetRecoveredAgents_1_ppMC5s"
I0815 04:13:49.095531  5277 credentials.hpp:86] Loading credential for auth=
entication from '/tmp/ContentType_MasterAPITest_GetRecoveredAgents_1_IKVhiq=
/credential'
I0815 04:13:49.095816  5277 slave.cpp:283] Agent using credential for: test=
-principal
I0815 04:13:49.095839  5277 credentials.hpp:37] Loading credentials for aut=
hentication from '/tmp/ContentType_MasterAPITest_GetRecoveredAgents_1_IKVhi=
q/http_credentials'
I0815 04:13:49.096245  5277 http.cpp:1026] Creating default 'basic' HTTP au=
thenticator for realm 'mesos-agent-readonly'
I0815 04:13:49.096525  5277 http.cpp:1026] Creating default 'basic' HTTP au=
thenticator for realm 'mesos-agent-readwrite'
I0815 04:13:49.100034  5277 slave.cpp:565] Agent resources: [{"name":"cpus"=
,"reservations":[{"role":"foo","type":"STATIC"}],"scalar":{"value":1.0},"ty=
pe":"SCALAR"},{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name=
":"mem","reservations":[{"role":"foo","type":"STATIC"}],"scalar":{"value":1=
024.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCA=
LAR"},{"name":"disk","reservations":[{"role":"foo","type":"STATIC"}],"scala=
r":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.=
0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end"=
:32000}]},"type":"RANGES"}]
I0815 04:13:49.100833  5277 slave.cpp:573] Agent attributes: [  ]
I0815 04:13:49.100864  5277 slave.cpp:582] Agent hostname: 1249dfeb6dc6
I0815 04:13:49.101241  5272 status_update_manager.cpp:177] Pausing sending =
status updates
I0815 04:13:49.103143  5274 state.cpp:64] Recovering state from '/tmp/Conte=
ntType_MasterAPITest_GetRecoveredAgents_1_ppMC5s/meta'
I0815 04:13:49.103606  5276 status_update_manager.cpp:203] Recovering statu=
s update manager
I0815 04:13:49.103926  5275 containerizer.cpp:598] Recovering containerizer
I0815 04:13:49.106240  5278 provisioner.cpp:416] Provisioner recovery compl=
ete
I0815 04:13:49.106899  5273 slave.cpp:6210] Finished recovery
I0815 04:13:49.107643  5273 slave.cpp:6392] Querying resource estimator for=
 oversubscribable resources
I0815 04:13:49.108119  5273 slave.cpp:971] New master detected at master@17=
2.17.0.2:34041
I0815 04:13:49.108158  5275 status_update_manager.cpp:177] Pausing sending =
status updates
I0815 04:13:49.108719  5273 slave.cpp:1006] Detecting new master
I0815 04:13:49.109053  5273 slave.cpp:6406] Received oversubscribable resou=
rces {} from the resource estimator
I0815 04:13:49.112154  5278 slave.cpp:1033] Authenticating with master mast=
er@172.17.0.2:34041
I0815 04:13:49.112341  5278 slave.cpp:1044] Using default CRAM-MD5 authenti=
catee
I0815 04:13:49.112920  5279 authenticatee.cpp:121] Creating new client SASL=
 connection
I0815 04:13:49.113580  5274 master.cpp:7837] Authenticating slave(624)@172.=
17.0.2:34041
I0815 04:13:49.113775  5277 authenticator.cpp:414] Starting authentication =
session for crammd5-authenticatee(1239)@172.17.0.2:34041
I0815 04:13:49.114253  5272 authenticator.cpp:98] Creating new server SASL =
connection
I0815 04:13:49.114925  5272 authenticatee.cpp:213] Received SASL authentica=
tion mechanisms: CRAM-MD5
I0815 04:13:49.114970  5272 authenticatee.cpp:239] Attempting to authentica=
te with mechanism 'CRAM-MD5'
I0815 04:13:49.115342  5272 authenticator.cpp:204] Received SASL authentica=
tion start
I0815 04:13:49.115586  5272 authenticator.cpp:326] Authentication requires =
more steps
I0815 04:13:49.115831  5273 authenticatee.cpp:259] Received SASL authentica=
tion step
I0815 04:13:49.116056  5278 authenticator.cpp:232] Received SASL authentica=
tion step
I0815 04:13:49.116142  5278 auxprop.cpp:109] Request to lookup properties f=
or user: 'test-principal' realm: '1249dfeb6dc6' server FQDN: '1249dfeb6dc6'=
 SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_=
AUXPROP_AUTHZID: false=20
I0815 04:13:49.116200  5278 auxprop.cpp:181] Looking up auxiliary property =
'*userPassword'
I0815 04:13:49.116291  5278 auxprop.cpp:181] Looking up auxiliary property =
'*cmusaslsecretCRAM-MD5'
I0815 04:13:49.116325  5278 auxprop.cpp:109] Request to lookup properties f=
or user: 'test-principal' realm: '1249dfeb6dc6' server FQDN: '1249dfeb6dc6'=
 SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_=
AUXPROP_AUTHZID: true=20
I0815 04:13:49.116370  5278 auxprop.cpp:131] Skipping auxiliary property '*=
userPassword' since SASL_AUXPROP_AUTHZID =3D=3D true
I0815 04:13:49.116390  5278 auxprop.cpp:131] Skipping auxiliary property '*=
cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID =3D=3D true
I0815 04:13:49.116453  5278 authenticator.cpp:318] Authentication success
I0815 04:13:49.116703  5279 authenticatee.cpp:299] Authentication success
I0815 04:13:49.116746  5274 master.cpp:7867] Successfully authenticated pri=
ncipal 'test-principal' at slave(624)@172.17.0.2:34041
I0815 04:13:49.116832  5277 authenticator.cpp:432] Authentication session c=
leanup for crammd5-authenticatee(1239)@172.17.0.2:34041
I0815 04:13:49.117169  5274 slave.cpp:1128] Successfully authenticated with=
 master master@172.17.0.2:34041
*** Aborted at 1502770429 (unix time) try "date -d @1502770429" if you are =
using GNU date ***
I0815 04:13:49.117516  5274 slave.cpp:1572] Will retry registration in 9370=
03ns if necessary
I0815 04:13:49.118046  5278 master.cpp:5712] Received register agent messag=
e from slave(624)@172.17.0.2:34041 (1249dfeb6dc6)
I0815 04:13:49.118335  5278 master.cpp:3803] Authorizing agent with princip=
al 'test-principal'
I0815 04:13:49.119123  5277 master.cpp:5772] Authorized registration of age=
nt at slave(624)@172.17.0.2:34041 (1249dfeb6dc6)
I0815 04:13:49.119285  5277 master.cpp:5865] Registering agent at slave(624=
)@172.17.0.2:34041 (1249dfeb6dc6) with id 6af4388b-cfda-4a01-8ce0-63d30f8e0=
2c1-S0
I0815 04:13:49.119846  5273 slave.cpp:1572] Will retry registration in 29.8=
86457ms if necessary
I0815 04:13:49.120093  5277 master.cpp:5706] Ignoring register agent messag=
e from slave(624)@172.17.0.2:34041 (1249dfeb6dc6) as registration is alread=
y in progress
I0815 04:13:49.120441  5275 registrar.cpp:495] Applied 1 operations in 1144=
69ns; attempting to update the registry
I0815 04:13:49.121773  5276 log.cpp:560] Attempting to append 414 bytes to =
the log
I0815 04:13:49.121917  5277 coordinator.cpp:348] Coordinator attempting to =
write APPEND action at position 3
I0815 04:13:49.123087  5276 replica.cpp:540] Replica received write request=
 for position 3 from __req_res__(1730)@172.17.0.2:34041
I0815 04:13:49.125586  5276 leveldb.cpp:341] Persisting action (433 bytes) =
to leveldb took 2.423399ms
I0815 04:13:49.125653  5276 replica.cpp:711] Persisted action APPEND at pos=
ition 3
I0815 04:13:49.126615  5275 replica.cpp:694] Replica received learned notic=
e for position 3 from log-network(98)@172.17.0.2:34041
I0815 04:13:49.128967  5275 leveldb.cpp:341] Persisting action (435 bytes) =
to leveldb took 2.279727ms
I0815 04:13:49.129045  5275 replica.cpp:711] Persisted action APPEND at pos=
ition 3
I0815 04:13:49.130678  5274 registrar.cpp:552] Successfully updated the reg=
istry in 10.119168ms
I0815 04:13:49.131175  5275 master.cpp:5912] Admitted agent 6af4388b-cfda-4=
a01-8ce0-63d30f8e02c1-S0 at slave(624)@172.17.0.2:34041 (1249dfeb6dc6)
I0815 04:13:49.131451  5273 log.cpp:579] Attempting to truncate the log to =
3
I0815 04:13:49.131709  5277 coordinator.cpp:348] Coordinator attempting to =
write TRUNCATE action at position 4
I0815 04:13:49.132887  5278 replica.cpp:540] Replica received write request=
 for position 4 from __req_res__(1731)@172.17.0.2:34041
I0815 04:13:49.132887  5273 slave.cpp:4887] Received ping from slave-observ=
er(595)@172.17.0.2:34041
I0815 04:13:49.133869  5273 slave.cpp:1174] Registered with master master@1=
72.17.0.2:34041; given agent ID 6af4388b-cfda-4a01-8ce0-63d30f8e02c1-S0
I0815 04:13:49.134389  5276 hierarchical.cpp:593] Added agent 6af4388b-cfda=
-4a01-8ce0-63d30f8e02c1-S0 (1249dfeb6dc6) with cpus(reservations: [(STATIC,=
foo)]):1; cpus:2; mem(reservations: [(STATIC,foo)]):1024; mem:1024; disk(re=
servations: [(STATIC,foo)]):1024; disk:1024; ports:[31000-32000] (allocated=
: {})
I0815 04:13:49.134495  5277 status_update_manager.cpp:184] Resuming sending=
 status updates
I0815 04:13:49.134757  5273 slave.cpp:1194] Checkpointing SlaveInfo to '/tm=
p/ContentType_MasterAPITest_GetRecoveredAgents_1_ppMC5s/meta/slaves/6af4388=
b-cfda-4a01-8ce0-63d30f8e02c1-S0/slave.info'
I0815 04:13:49.134927  5278 leveldb.cpp:341] Persisting action (16 bytes) t=
o leveldb took 1.889312ms
I0815 04:13:49.134979  5278 replica.cpp:711] Persisted action TRUNCATE at p=
osition 4
I0815 04:13:49.135062  5276 hierarchical.cpp:1943] No allocations performed
I0815 04:13:49.135136  5276 hierarchical.cpp:1486] Performed allocation for=
 1 agents in 383747ns
I0815 04:13:49.133396  5275 master.cpp:5943] Registered agent 6af4388b-cfda=
-4a01-8ce0-63d30f8e02c1-S0 at slave(624)@172.17.0.2:34041 (1249dfeb6dc6) wi=
th [{"name":"cpus","reservations":[{"role":"foo","type":"STATIC"}],"scalar"=
:{"value":1.0},"type":"SCALAR"},{"name":"cpus","scalar":{"value":2.0},"type=
":"SCALAR"},{"name":"mem","reservations":[{"role":"foo","type":"STATIC"}],"=
scalar":{"value":1024.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1=
024.0},"type":"SCALAR"},{"name":"disk","reservations":[{"role":"foo","type"=
:"STATIC"}],"scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scal=
ar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"=
begin":31000,"end":32000}]},"type":"RANGES"}]
I0815 04:13:49.135702  5273 slave.cpp:1232] Forwarding total oversubscribed=
 resources {}
I0815 04:13:49.136065  5273 replica.cpp:694] Replica received learned notic=
e for position 4 from log-network(98)@172.17.0.2:34041
I0815 04:13:49.136471  5275 master.cpp:6688] Received update of agent 6af43=
88b-cfda-4a01-8ce0-63d30f8e02c1-S0 at slave(624)@172.17.0.2:34041 (1249dfeb=
6dc6) with total oversubscribed resources {}
I0815 04:13:49.137473  5274 hierarchical.cpp:660] Agent 6af4388b-cfda-4a01-=
8ce0-63d30f8e02c1-S0 (1249dfeb6dc6) updated with total resources cpus(reser=
vations: [(STATIC,foo)]):1; cpus:2; mem(reservations: [(STATIC,foo)]):1024;=
 mem:1024; disk(reservations: [(STATIC,foo)]):1024; disk:1024; ports:[31000=
-32000]
I0815 04:13:49.138626  5273 leveldb.cpp:341] Persisting action (18 bytes) t=
o leveldb took 2.458547ms
I0815 04:13:49.138806  5273 leveldb.cpp:399] Deleting ~2 keys from leveldb =
took 83571ns
I0815 04:13:49.138917  5273 replica.cpp:711] Persisted action TRUNCATE at p=
osition 4
I0815 04:13:49.141507  5278 process.cpp:3933] Handling HTTP event for proce=
ss 'master' with path: '/master/reserve'
I0815 04:13:49.144131  5278 http.cpp:1166] HTTP POST for /master/reserve fr=
om 172.17.0.2:37486
I0815 04:13:49.145411  5278 master.cpp:3588] Authorizing principal 'test-pr=
incipal' to reserve resources '[{"name":"cpus","reservations":[{"principal"=
:"test-principal","role":"bar","type":"DYNAMIC"}],"scalar":{"value":1.0},"t=
ype":"SCALAR"},{"name":"mem","reservations":[{"principal":"test-principal",=
"role":"bar","type":"DYNAMIC"}],"scalar":{"value":12.0},"type":"SCALAR"}]'
I0815 04:13:49.152593  5277 master.cpp:9110] Sending updated checkpointed r=
esources cpus(reservations: [(DYNAMIC,bar,test-principal)]):1; mem(reservat=
ions: [(DYNAMIC,bar,test-principal)]):12 to agent 6af4388b-cfda-4a01-8ce0-6=
3d30f8e02c1-S0 at slave(624)@172.17.0.2:34041 (1249dfeb6dc6)
PC: @     0x2b81fb4a2b12 process::EventQueue::Consumer::empty()
I0815 04:13:49.154256  5276 slave.cpp:3449] Updated checkpointed resources =
from {} to cpus(reservations: [(DYNAMIC,bar,test-principal)]):1; mem(reserv=
ations: [(DYNAMIC,bar,test-principal)]):12
I0815 04:13:49.159668  5277 process.cpp:3933] Handling HTTP event for proce=
ss 'master' with path: '/master/api/v1'
*** SIGSEGV (@0x8) received by PID 5253 (TID 0x2b8206eb2700) from PID 8; st=
ack trace: ***
    @     0x2b8215973417 (unknown)
I0815 04:13:49.162364  5277 http.cpp:1166] HTTP POST for /master/api/v1 fro=
m 172.17.0.2:37488
I0815 04:13:49.162587  5277 http.cpp:673] Processing call GET_AGENTS
    @     0x2b82159776f9 (unknown)
    @     0x2b81fdb41330 (unknown)
I0815 04:13:49.176342  5253 master.cpp:1160] Master terminating
I0815 04:13:49.178910  5274 hierarchical.cpp:626] Removed agent 6af4388b-cf=
da-4a01-8ce0-63d30f8e02c1-S0
I0815 04:13:49.179749  5278 slave.cpp:4929] Got exited event for master@172=
.17.0.2:34041
W0815 04:13:49.179852  5278 slave.cpp:4934] Master disconnected! Waiting fo=
r a new master to be elected
    @     0x2b81fb4a2b12 process::EventQueue::Consumer::empty()
I0815 04:13:49.185911  5278 slave.cpp:843] Agent terminating
    @     0x2b81fb48f7c0 process::ProcessManager::resume()
    @     0x2b81fb48bdbc _ZZN7process14ProcessManager12init_threadsEvENKUlv=
E_clEv
I0815 04:13:49.197295  5253 cluster.cpp:162] Creating default 'local' autho=
rizer
    @     0x2b81fb49d52a _ZNSt12_Bind_simpleIFZN7process14ProcessManager12i=
nit_threadsEvEUlvE_vEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE
    @     0x2b81fb49d481 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12i=
nit_threadsEvEUlvE_vEEclEv
    @     0x2b81fb49d41a _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14P=
rocessManager12init_threadsEvEUlvE_vEEE6_M_runEv
    @     0x2b81fd3c2a60 (unknown)
    @     0x2b81fdb39184 start_thread
    @     0x2b81fde4cffd (unknown)
make[4]: *** [check-local] Segmentation fault (core dumped)
make[4]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-1.4.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1502763897-29537
Untagged: mesos-1502763897-29537:latest
Deleted: sha256:ddbc363bfd4e2cd0f11999b7aa6fd1faf40c20b68f5cc766a58738ec6a5=
97087
Deleted: sha256:6070afbeaea720145ef2297209034cffc8a2be5aadd294ac115c11aa350=
b2e50
Deleted: sha256:df32815293c87d047f9d1e1dfd57b770687918d5459e6a9ce3dc346b8a9=
e61e5
Deleted: sha256:93ac60f0956b5bf63f7c71b63fab1edbc7f9e3aa3c3c27cd9e023d00a45=
53270
Deleted: sha256:2746f2f5784961632db4b8d3010b1930c6ce7fad2f93b35acc74c43ec53=
31c0c
Deleted: sha256:1443750bf56765ea4a377d0ca654b40ca8a18a1ebcfed21a445c3748b12=
2d5a4
Deleted: sha256:ab0d8e76aa1e4165a12df9191d8899dda3e1fe0a0946a6f3b337dc8317c=
587f2
Deleted: sha256:23f8323174340003ae3e2c537a73d2ec4db8a2814875b453be69c5f0b64=
f7c6e
Deleted: sha256:5352200e0f08cf3e289a03bb2c30dbe8f65bce5dac428b94a31c49624d0=
ae13d
Deleted: sha256:fb4580ebc5aadca90e39f296bacf7f7e807ea234e226e974140c31d9cfc=
d3815
Deleted: sha256:b81950bf00fbf87f45583aa036355098835db1441cea3dc805d2923d6ed=
caafa
Deleted: sha256:c81eccf7b10e1b3d9daf693ad260a3776cc554cec0ef4494e7078049209=
41c52
Deleted: sha256:3865075c11bbd2b73aa0c33915de47c04c1a27403ea871e6e9a0275851b=
36349
Deleted: sha256:63834f01eeadee54f0921df79b280d1c8a4b2a8b69b9b8ebd1f3dd0ba1a=
7e39e
Deleted: sha256:f5192672820661795b4b0b208d7c5d63760831bba5169e4877e68366fd3=
46558
Deleted: sha256:a757e02028971c035489a282187b09bd035352d6af6d41786446ff4b4ef=
6cdfb
Deleted: sha256:04810eaaff1ff3ceee9e134e2585854697b0a69f82b967363683f21842c=
2e689
Deleted: sha256:31c5d0d197e5b5adaf5f5e65471856c6f3909d4f2e7bd059cfee54672b1=
93f8e
Deleted: sha256:3a30adb725fc4e4b85602740068d512cab902acf38bfd3d210cc33f3fe5=
63eef
Deleted: sha256:a610517ce8b917f86dbedb5f50ac31e29f8d431981cf8766290082625a0=
32c90
Deleted: sha256:90631604711e2a177ededd5be448a82a7297952f80ecf5d351a51b5e22b=
906b1
Deleted: sha256:afa1432919ba2d477f8f0961d05db91c52cc075ef42abe53377ee92a59f=
ee287
Deleted: sha256:961ca0ce9c0900bdc0e535c34a56a5e7b168f34b1671b526b12f025886a=
34851
Deleted: sha256:422cf0802a5947308c1879ca905e96106d1d7fad0b47d794d3be307eee9=
05bb8
Build step 'Execute shell' marked build as failure