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/09/21 01:02:15 UTC
Build failed in Jenkins: mesos-reviewbot #15339
See <https://builds.apache.org/job/mesos-reviewbot/15339/changes>
Changes:
[mpark] Fixed a typo in `docker_containerizer_tests.cpp`.
------------------------------------------
Started by an SCM change
Started by an SCM change
Started by an SCM change
Started by an SCM change
[URLTrigger] A change within the response URL invocation (log)
[URLTrigger] A change within the response URL invocation (log)
[URLTrigger] A change within the response URL invocation (log)
[EnvInject] - Loading node environment variables.
Building remotely on ubuntu-4 (Ubuntu yahoo-not-h2 ubuntu ubuntu4 docker) in workspace <https://builds.apache.org/job/mesos-reviewbot/ws/>
> git rev-parse --is-inside-work-tree # timeout=10
Fetching changes from the remote Git repository
> git config remote.origin.url https://git-wip-us.apache.org/repos/asf/mesos.git # timeout=10
Fetching upstream changes from https://git-wip-us.apache.org/repos/asf/mesos.git
> git --version # timeout=10
> git -c core.askpass=true fetch --tags --progress https://git-wip-us.apache.org/repos/asf/mesos.git +refs/heads/*:refs/remotes/origin/*
> git rev-parse origin/master^{commit} # timeout=10
Checking out Revision 9303db67c3c7ac4206c4f35fadaa15bd07a77129 (origin/master)
> git config core.sparsecheckout # timeout=10
> git checkout -f 9303db67c3c7ac4206c4f35fadaa15bd07a77129
> git rev-list 46379ba533f6715ad170adb55d3b28da39931944 # timeout=10
> git tag -a -f -m Jenkins Build #15339 jenkins-mesos-reviewbot-15339 # timeout=10
[mesos-reviewbot] $ /bin/bash -xe /tmp/hudson7883207436826751563.sh
+ date
Wed Sep 21 00:57:56 UTC 2016
+ ./support/mesos-style.py
include/mesos/version.hpp:1: A license header should appear on the file's first line starting with '// Licensed'.: /**
Total errors found: 1
Checking 1037 files
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : mesos-reviewbot #15341
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/15341/changes>
Build failed in Jenkins: mesos-reviewbot #15340
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/15340/>
------------------------------------------
[...truncated 311313 lines...]
I0921 04:17:51.848589 28954 slave.cpp:533] Agent resources: cpus(*):1; mem(*):64; disk(*):3701220; ports(*):[31000-32000]
I0921 04:17:51.848704 28954 slave.cpp:541] Agent attributes: [ ]
I0921 04:17:51.848727 28954 slave.cpp:546] Agent hostname: 043a9b4c246b
I0921 04:17:51.848845 28966 authenticatee.cpp:121] Creating new client SASL connection
I0921 04:17:51.849128 28959 master.cpp:6583] Authenticating scheduler-d1b40327-0a57-4ed2-83af-f616c102316b@172.17.0.2:51750
I0921 04:17:51.849228 28957 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(433)@172.17.0.2:51750
I0921 04:17:51.849436 28962 authenticator.cpp:98] Creating new server SASL connection
I0921 04:17:51.849685 28959 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0921 04:17:51.849792 28959 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0921 04:17:51.849923 28960 authenticator.cpp:204] Received SASL authentication start
I0921 04:17:51.849995 28960 authenticator.cpp:326] Authentication requires more steps
I0921 04:17:51.850095 28959 authenticatee.cpp:259] Received SASL authentication step
I0921 04:17:51.850253 28959 authenticator.cpp:232] Received SASL authentication step
I0921 04:17:51.850327 28959 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '043a9b4c246b' server FQDN: '043a9b4c246b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0921 04:17:51.850481 28959 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0921 04:17:51.850529 28959 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0921 04:17:51.850563 28959 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '043a9b4c246b' server FQDN: '043a9b4c246b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0921 04:17:51.850584 28959 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0921 04:17:51.850597 28959 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0921 04:17:51.850682 28958 state.cpp:57] Recovering state from '/tmp/MasterTest_UnacknowledgedTerminalTask_dX3WyA/meta'
I0921 04:17:51.850685 28959 authenticator.cpp:318] Authentication success
I0921 04:17:51.850808 28954 authenticatee.cpp:299] Authentication success
I0921 04:17:51.850967 28960 master.cpp:6613] Successfully authenticated principal 'test-principal' at scheduler-d1b40327-0a57-4ed2-83af-f616c102316b@172.17.0.2:51750
I0921 04:17:51.851058 28951 status_update_manager.cpp:203] Recovering status update manager
I0921 04:17:51.851160 28956 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(433)@172.17.0.2:51750
I0921 04:17:51.851335 28961 sched.cpp:502] Successfully authenticated with master master@172.17.0.2:51750
I0921 04:17:51.851363 28961 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.2:51750
I0921 04:17:51.851452 28961 sched.cpp:853] Will retry registration in 1.979063342secs if necessary
I0921 04:17:51.851588 28964 slave.cpp:5227] Finished recovery
I0921 04:17:51.851642 28961 master.cpp:2587] Received SUBSCRIBE call for framework 'default' at scheduler-d1b40327-0a57-4ed2-83af-f616c102316b@172.17.0.2:51750
I0921 04:17:51.851699 28961 master.cpp:2049] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0921 04:17:51.852237 28961 master.cpp:2663] Subscribing framework default with checkpointing disabled and capabilities [ ]
I0921 04:17:51.852787 28963 sched.cpp:743] Framework registered with 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:51.852807 28966 hierarchical.cpp:272] Added framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:51.852875 28963 sched.cpp:757] Scheduler::registered took 62041ns
I0921 04:17:51.852881 28966 hierarchical.cpp:1685] No allocations performed
I0921 04:17:51.853073 28966 hierarchical.cpp:1780] No inverse offers to send out!
I0921 04:17:51.853170 28966 hierarchical.cpp:1277] Performed allocation for 0 agents in 335992ns
I0921 04:17:51.872225 28964 slave.cpp:5399] Querying resource estimator for oversubscribable resources
I0921 04:17:51.872756 28964 slave.cpp:915] New master detected at master@172.17.0.2:51750
I0921 04:17:51.872778 28964 slave.cpp:974] Authenticating with master master@172.17.0.2:51750
I0921 04:17:51.872788 28956 status_update_manager.cpp:177] Pausing sending status updates
I0921 04:17:51.872839 28964 slave.cpp:985] Using default CRAM-MD5 authenticatee
I0921 04:17:51.872999 28964 slave.cpp:947] Detecting new master
I0921 04:17:51.873106 28963 authenticatee.cpp:121] Creating new client SASL connection
I0921 04:17:51.873208 28964 slave.cpp:5413] Received oversubscribable resources from the resource estimator
I0921 04:17:51.873513 28958 master.cpp:6583] Authenticating slave(190)@172.17.0.2:51750
I0921 04:17:51.873651 28964 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(434)@172.17.0.2:51750
I0921 04:17:51.873986 28954 authenticator.cpp:98] Creating new server SASL connection
I0921 04:17:51.874335 28965 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0921 04:17:51.874373 28965 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0921 04:17:51.874505 28965 authenticator.cpp:204] Received SASL authentication start
I0921 04:17:51.874578 28965 authenticator.cpp:326] Authentication requires more steps
I0921 04:17:51.874725 28956 authenticatee.cpp:259] Received SASL authentication step
I0921 04:17:51.874899 28962 authenticator.cpp:232] Received SASL authentication step
I0921 04:17:51.874938 28962 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '043a9b4c246b' server FQDN: '043a9b4c246b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0921 04:17:51.874956 28962 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0921 04:17:51.875000 28962 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0921 04:17:51.875027 28962 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '043a9b4c246b' server FQDN: '043a9b4c246b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0921 04:17:51.875049 28962 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0921 04:17:51.875063 28962 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0921 04:17:51.875083 28962 authenticator.cpp:318] Authentication success
I0921 04:17:51.875216 28957 authenticatee.cpp:299] Authentication success
I0921 04:17:51.875336 28961 master.cpp:6613] Successfully authenticated principal 'test-principal' at slave(190)@172.17.0.2:51750
I0921 04:17:51.875442 28963 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(434)@172.17.0.2:51750
I0921 04:17:51.875706 28966 slave.cpp:1069] Successfully authenticated with master master@172.17.0.2:51750
I0921 04:17:51.875934 28966 slave.cpp:1475] Will retry registration in 4.924259ms if necessary
I0921 04:17:51.876178 28961 master.cpp:5040] Registering agent at slave(190)@172.17.0.2:51750 (043a9b4c246b) with id 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0
I0921 04:17:51.876837 28962 registrar.cpp:461] Applied 1 operations in 79795ns; attempting to update the registry
I0921 04:17:51.877873 28958 log.cpp:577] Attempting to append 337 bytes to the log
I0921 04:17:51.878056 28960 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3
I0921 04:17:51.879194 28954 replica.cpp:537] Replica received write request for position 3 from __req_res__(3007)@172.17.0.2:51750
I0921 04:17:51.881566 28962 slave.cpp:1475] Will retry registration in 29.920965ms if necessary
I0921 04:17:51.881712 28964 master.cpp:5028] Ignoring register agent message from slave(190)@172.17.0.2:51750 (043a9b4c246b) as admission is already in progress
I0921 04:17:51.882606 28965 hierarchical.cpp:1685] No allocations performed
I0921 04:17:51.882647 28965 hierarchical.cpp:1780] No inverse offers to send out!
I0921 04:17:51.882733 28965 hierarchical.cpp:1277] Performed allocation for 0 agents in 196326ns
I0921 04:17:51.912089 28958 slave.cpp:1475] Will retry registration in 54.989715ms if necessary
I0921 04:17:51.912263 28952 master.cpp:5028] Ignoring register agent message from slave(190)@172.17.0.2:51750 (043a9b4c246b) as admission is already in progress
I0921 04:17:51.945797 28954 leveldb.cpp:341] Persisting action (356 bytes) to leveldb took 66.541786ms
I0921 04:17:51.945842 28954 replica.cpp:708] Persisted action APPEND at position 3
I0921 04:17:51.946879 28956 replica.cpp:691] Replica received learned notice for position 3 from @0.0.0.0:0
I0921 04:17:51.967705 28965 slave.cpp:1475] Will retry registration in 5.436762ms if necessary
I0921 04:17:51.967895 28954 master.cpp:5028] Ignoring register agent message from slave(190)@172.17.0.2:51750 (043a9b4c246b) as admission is already in progress
I0921 04:17:51.974359 28951 slave.cpp:1475] Will retry registration in 63.436491ms if necessary
I0921 04:17:51.974531 28966 master.cpp:5028] Ignoring register agent message from slave(190)@172.17.0.2:51750 (043a9b4c246b) as admission is already in progress
I0921 04:17:52.029913 28956 leveldb.cpp:341] Persisting action (358 bytes) to leveldb took 82.910709ms
I0921 04:17:52.029989 28956 replica.cpp:708] Persisted action APPEND at position 3
I0921 04:17:52.032229 28951 registrar.cpp:506] Successfully updated the registry in 155.302912ms
I0921 04:17:52.032532 28959 log.cpp:596] Attempting to truncate the log to 3
I0921 04:17:52.032754 28966 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 4
I0921 04:17:52.033639 28958 slave.cpp:4089] Received ping from slave-observer(190)@172.17.0.2:51750
I0921 04:17:52.033654 28955 master.cpp:5111] Registered agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 at slave(190)@172.17.0.2:51750 (043a9b4c246b) with cpus(*):1; mem(*):64; disk(*):3701220; ports(*):[31000-32000]
I0921 04:17:52.033819 28958 slave.cpp:1115] Registered with master master@172.17.0.2:51750; given agent ID 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0
I0921 04:17:52.033845 28958 fetcher.cpp:86] Clearing fetcher cache
I0921 04:17:52.033861 28957 replica.cpp:537] Replica received write request for position 4 from __req_res__(3008)@172.17.0.2:51750
I0921 04:17:52.033998 28959 status_update_manager.cpp:184] Resuming sending status updates
I0921 04:17:52.034078 28965 hierarchical.cpp:482] Added agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 (043a9b4c246b) with cpus(*):1; mem(*):64; disk(*):3701220; ports(*):[31000-32000] (allocated: )
I0921 04:17:52.034281 28958 slave.cpp:1138] Checkpointing SlaveInfo to '/tmp/MasterTest_UnacknowledgedTerminalTask_dX3WyA/meta/slaves/4200f99d-a497-4137-8afd-f306d2bb0f3a-S0/slave.info'
I0921 04:17:52.034667 28958 slave.cpp:1175] Forwarding total oversubscribed resources
I0921 04:17:52.034862 28964 master.cpp:5508] Received update of agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 at slave(190)@172.17.0.2:51750 (043a9b4c246b) with total oversubscribed resources
I0921 04:17:52.035249 28965 hierarchical.cpp:1780] No inverse offers to send out!
I0921 04:17:52.035318 28965 hierarchical.cpp:1300] Performed allocation for agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 in 1.194563ms
I0921 04:17:52.035434 28965 hierarchical.cpp:546] Agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 (043a9b4c246b) updated with oversubscribed resources (total: cpus(*):1; mem(*):64; disk(*):3701220; ports(*):[31000-32000], allocated: cpus(*):1; mem(*):64; disk(*):3701220; ports(*):[31000-32000])
I0921 04:17:52.035536 28965 hierarchical.cpp:1685] No allocations performed
I0921 04:17:52.035565 28965 hierarchical.cpp:1780] No inverse offers to send out!
I0921 04:17:52.035604 28965 hierarchical.cpp:1300] Performed allocation for agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 in 135498ns
I0921 04:17:52.035704 28958 master.cpp:6412] Sending 1 offers to framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 (default) at scheduler-d1b40327-0a57-4ed2-83af-f616c102316b@172.17.0.2:51750
I0921 04:17:52.037067 28960 sched.cpp:917] Scheduler::resourceOffers took 1.02045ms
I0921 04:17:52.038234 28966 master.cpp:3521] Processing ACCEPT call for offers: [ 4200f99d-a497-4137-8afd-f306d2bb0f3a-O0 ] on agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 at slave(190)@172.17.0.2:51750 (043a9b4c246b) for framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 (default) at scheduler-d1b40327-0a57-4ed2-83af-f616c102316b@172.17.0.2:51750
I0921 04:17:52.038383 28966 master.cpp:3143] Authorizing framework principal 'test-principal' to launch task 0
W0921 04:17:52.039953 28966 validation.cpp:916] Executor 'default' for task '0' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
W0921 04:17:52.039985 28966 validation.cpp:928] Executor 'default' for task '0' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
I0921 04:17:52.040272 28966 master.cpp:8159] Adding task 0 with resources cpus(*):1; mem(*):64 on agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 (043a9b4c246b)
I0921 04:17:52.040407 28966 master.cpp:4121] Launching task 0 of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 (default) at scheduler-d1b40327-0a57-4ed2-83af-f616c102316b@172.17.0.2:51750 with resources cpus(*):1; mem(*):64 on agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 at slave(190)@172.17.0.2:51750 (043a9b4c246b)
I0921 04:17:52.040762 28961 slave.cpp:1539] Got assigned task '0' for framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:52.041293 28961 slave.cpp:1696] Launching task '0' for framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:52.041656 28965 hierarchical.cpp:1009] Recovered ports(*):[31000-32000]; disk(*):3701220 (total: cpus(*):1; mem(*):64; disk(*):3701220; ports(*):[31000-32000], allocated: cpus(*):1; mem(*):64) on agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 from framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:52.041704 28965 hierarchical.cpp:1046] Framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 filtered agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 for 5secs
I0921 04:17:52.041970 28961 paths.cpp:536] Trying to chown '/tmp/MasterTest_UnacknowledgedTerminalTask_dX3WyA/slaves/4200f99d-a497-4137-8afd-f306d2bb0f3a-S0/frameworks/4200f99d-a497-4137-8afd-f306d2bb0f3a-0000/executors/default/runs/60fc98d6-23ec-4607-bac6-a252dedb2c53' to user 'mesos'
I0921 04:17:52.053012 28961 slave.cpp:6110] Launching executor 'default' of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 with resources in work directory '/tmp/MasterTest_UnacknowledgedTerminalTask_dX3WyA/slaves/4200f99d-a497-4137-8afd-f306d2bb0f3a-S0/frameworks/4200f99d-a497-4137-8afd-f306d2bb0f3a-0000/executors/default/runs/60fc98d6-23ec-4607-bac6-a252dedb2c53'
I0921 04:17:52.056272 28961 exec.cpp:162] Version: 1.1.0
I0921 04:17:52.056753 28960 exec.cpp:212] Executor started at: executor(80)@172.17.0.2:51750 with pid 28932
I0921 04:17:52.057034 28961 slave.cpp:1982] Queued task '0' for executor 'default' of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:52.057102 28961 slave.cpp:868] Successfully attached file '/tmp/MasterTest_UnacknowledgedTerminalTask_dX3WyA/slaves/4200f99d-a497-4137-8afd-f306d2bb0f3a-S0/frameworks/4200f99d-a497-4137-8afd-f306d2bb0f3a-0000/executors/default/runs/60fc98d6-23ec-4607-bac6-a252dedb2c53'
I0921 04:17:52.057303 28961 slave.cpp:3203] Got registration for executor 'default' of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 from executor(80)@172.17.0.2:51750
I0921 04:17:52.057709 28962 exec.cpp:237] Executor registered on agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0
I0921 04:17:52.057780 28962 exec.cpp:249] Executor::registered took 44889ns
I0921 04:17:52.058010 28961 slave.cpp:2186] Sending queued task '0' to executor 'default' of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 at executor(80)@172.17.0.2:51750
I0921 04:17:52.058396 28966 exec.cpp:324] Executor asked to run task '0'
I0921 04:17:52.058488 28966 exec.cpp:333] Executor::launchTask took 68613ns
I0921 04:17:52.058593 28966 exec.cpp:550] Executor sending status update TASK_FINISHED (UUID: fdbba50f-9ab7-45a2-9361-9fc112ee285d) for task 0 of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:52.058900 28956 slave.cpp:3606] Handling status update TASK_FINISHED (UUID: fdbba50f-9ab7-45a2-9361-9fc112ee285d) for task 0 of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 from executor(80)@172.17.0.2:51750
I0921 04:17:52.059706 28966 status_update_manager.cpp:323] Received status update TASK_FINISHED (UUID: fdbba50f-9ab7-45a2-9361-9fc112ee285d) for task 0 of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:52.059754 28966 status_update_manager.cpp:500] Creating StatusUpdate stream for task 0 of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:52.060204 28966 status_update_manager.cpp:377] Forwarding update TASK_FINISHED (UUID: fdbba50f-9ab7-45a2-9361-9fc112ee285d) for task 0 of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 to the agent
I0921 04:17:52.060492 28965 slave.cpp:4007] Forwarding the update TASK_FINISHED (UUID: fdbba50f-9ab7-45a2-9361-9fc112ee285d) for task 0 of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 to master@172.17.0.2:51750
I0921 04:17:52.061067 28965 slave.cpp:3901] Status update manager successfully handled status update TASK_FINISHED (UUID: fdbba50f-9ab7-45a2-9361-9fc112ee285d) for task 0 of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:52.061136 28965 slave.cpp:3917] Sending acknowledgement for status update TASK_FINISHED (UUID: fdbba50f-9ab7-45a2-9361-9fc112ee285d) for task 0 of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 to executor(80)@172.17.0.2:51750
I0921 04:17:52.061197 28963 master.cpp:5638] Status update TASK_FINISHED (UUID: fdbba50f-9ab7-45a2-9361-9fc112ee285d) for task 0 of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 from agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 at slave(190)@172.17.0.2:51750 (043a9b4c246b)
I0921 04:17:52.061275 28963 master.cpp:5700] Forwarding status update TASK_FINISHED (UUID: fdbba50f-9ab7-45a2-9361-9fc112ee285d) for task 0 of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:52.061444 28956 exec.cpp:373] Executor received status update acknowledgement fdbba50f-9ab7-45a2-9361-9fc112ee285d for task 0 of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:52.061607 28963 master.cpp:7537] Updating the state of task 0 of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 (latest state: TASK_FINISHED, status update state: TASK_FINISHED)
I0921 04:17:52.062386 28959 hierarchical.cpp:1009] Recovered cpus(*):1; mem(*):64 (total: cpus(*):1; mem(*):64; disk(*):3701220; ports(*):[31000-32000], allocated: ) on agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 from framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:52.063985 28961 hierarchical.cpp:1780] No inverse offers to send out!
I0921 04:17:52.064086 28961 hierarchical.cpp:1277] Performed allocation for 1 agents in 1.052104ms
I0921 04:17:52.064530 28951 master.cpp:6412] Sending 1 offers to framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 (default) at scheduler-d1b40327-0a57-4ed2-83af-f616c102316b@172.17.0.2:51750
I0921 04:17:52.065065 28951 sched.cpp:917] Scheduler::resourceOffers took 105586ns
I0921 04:17:52.065611 28932 sched.cpp:1995] Asked to stop the driver
I0921 04:17:52.065728 28953 sched.cpp:1187] Stopping framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:52.065969 28954 master.cpp:6988] Processing TEARDOWN call for framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 (default) at scheduler-d1b40327-0a57-4ed2-83af-f616c102316b@172.17.0.2:51750
I0921 04:17:52.066011 28954 master.cpp:7000] Removing framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 (default) at scheduler-d1b40327-0a57-4ed2-83af-f616c102316b@172.17.0.2:51750
I0921 04:17:52.066161 28961 hierarchical.cpp:383] Deactivated framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:52.066262 28954 master.cpp:7537] Updating the state of task 0 of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 (latest state: TASK_FINISHED, status update state: TASK_KILLED)
I0921 04:17:52.066339 28959 slave.cpp:2506] Asked to shut down framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 by master@172.17.0.2:51750
I0921 04:17:52.066314 28954 master.cpp:7633] Removing task 0 with resources cpus(*):1; mem(*):64 of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 on agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 at slave(190)@172.17.0.2:51750 (043a9b4c246b)
I0921 04:17:52.066385 28959 slave.cpp:2531] Shutting down framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:52.066442 28959 slave.cpp:4810] Shutting down executor 'default' of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 at executor(80)@172.17.0.2:51750
I0921 04:17:52.066558 28951 exec.cpp:414] Executor asked to shutdown
I0921 04:17:52.066612 28951 exec.cpp:429] Executor::shutdown took 29310ns
I0921 04:17:52.066782 28951 slave.cpp:4135] Got exited event for executor(80)@172.17.0.2:51750
I0921 04:17:52.067093 28954 master.cpp:7662] Removing executor 'default' with resources of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 on agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 at slave(190)@172.17.0.2:51750 (043a9b4c246b)
I0921 04:17:52.067373 28961 slave.cpp:4492] Executor 'default' of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 exited with status 0
I0921 04:17:52.067453 28961 slave.cpp:4596] Cleaning up executor 'default' of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 at executor(80)@172.17.0.2:51750
W0921 04:17:52.067595 28954 master.cpp:5756] Ignoring unknown exited executor 'default' of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000 on agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 at slave(190)@172.17.0.2:51750 (043a9b4c246b)
I0921 04:17:52.067617 28966 hierarchical.cpp:1009] Recovered cpus(*):1; mem(*):64; disk(*):3701220; ports(*):[31000-32000] (total: cpus(*):1; mem(*):64; disk(*):3701220; ports(*):[31000-32000], allocated: ) on agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 from framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:52.067920 28966 hierarchical.cpp:334] Removed framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:52.074592 28964 gc.cpp:55] Scheduling '/tmp/MasterTest_UnacknowledgedTerminalTask_dX3WyA/slaves/4200f99d-a497-4137-8afd-f306d2bb0f3a-S0/frameworks/4200f99d-a497-4137-8afd-f306d2bb0f3a-0000/executors/default/runs/60fc98d6-23ec-4607-bac6-a252dedb2c53' for gc 6.9999991381363days in the future
I0921 04:17:52.074689 28961 slave.cpp:4684] Cleaning up framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:52.074748 28964 gc.cpp:55] Scheduling '/tmp/MasterTest_UnacknowledgedTerminalTask_dX3WyA/slaves/4200f99d-a497-4137-8afd-f306d2bb0f3a-S0/frameworks/4200f99d-a497-4137-8afd-f306d2bb0f3a-0000/executors/default' for gc 6.99999913610963days in the future
I0921 04:17:52.074777 28965 status_update_manager.cpp:285] Closing status update streams for framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:52.074852 28965 status_update_manager.cpp:531] Cleaning up status update stream for task 0 of framework 4200f99d-a497-4137-8afd-f306d2bb0f3a-0000
I0921 04:17:52.074856 28961 slave.cpp:787] Agent terminating
I0921 04:17:52.074878 28964 gc.cpp:55] Scheduling '/tmp/MasterTest_UnacknowledgedTerminalTask_dX3WyA/slaves/4200f99d-a497-4137-8afd-f306d2bb0f3a-S0/frameworks/4200f99d-a497-4137-8afd-f306d2bb0f3a-0000' for gc 6.99999913435259days in the future
I0921 04:17:52.075093 28953 master.cpp:1258] Agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 at slave(190)@172.17.0.2:51750 (043a9b4c246b) disconnected
I0921 04:17:52.075122 28953 master.cpp:2947] Disconnecting agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 at slave(190)@172.17.0.2:51750 (043a9b4c246b)
I0921 04:17:52.075187 28953 master.cpp:2966] Deactivating agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 at slave(190)@172.17.0.2:51750 (043a9b4c246b)
I0921 04:17:52.075358 28965 hierarchical.cpp:575] Agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0 deactivated
I0921 04:17:52.078038 28932 master.cpp:1097] Master terminating
I0921 04:17:52.078817 28963 hierarchical.cpp:514] Removed agent 4200f99d-a497-4137-8afd-f306d2bb0f3a-S0
I0921 04:17:52.083061 28957 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 49.137051ms
I0921 04:17:52.083101 28957 replica.cpp:708] Persisted action TRUNCATE at position 4
[ OK ] MasterTest.UnacknowledgedTerminalTask (1627 ms)
[ RUN ] MasterTest.ReleaseResourcesForTerminalTaskWithPendingUpdates
I0921 04:17:52.113205 28932 cluster.cpp:158] Creating default 'local' authorizer
I0921 04:17:52.359547 28932 leveldb.cpp:174] Opened db in 246.067804ms
I0921 04:17:52.469465 28932 leveldb.cpp:181] Compacted db in 109.84446ms
I0921 04:17:52.469565 28932 leveldb.cpp:196] Created db iterator in 29973ns
I0921 04:17:52.469588 28932 leveldb.cpp:202] Seeked to beginning of db in 3097ns
I0921 04:17:52.469599 28932 leveldb.cpp:271] Iterated through 0 keys in the db in 648ns
I0921 04:17:52.469655 28932 replica.cpp:776] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0921 04:17:52.470509 28965 recover.cpp:451] Starting replica recovery
I0921 04:17:52.470829 28965 recover.cpp:477] Replica is in EMPTY status
I0921 04:17:52.472110 28960 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from __req_res__(3009)@172.17.0.2:51750
I0921 04:17:52.472731 28953 recover.cpp:197] Received a recover response from a replica in EMPTY status
I0921 04:17:52.473420 28966 recover.cpp:568] Updating replica status to STARTING
I0921 04:17:52.474642 28966 master.cpp:380] Master 640ab2e9-c9f3-4cc4-84f2-35fe21db547d (043a9b4c246b) started on 172.17.0.2:51750
I0921 04:17:52.474670 28966 master.cpp:382] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/hJt3y8/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --quiet="false" --recovery_agent_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-1.1.0/_inst/share/mesos/webui" --work_dir="/tmp/hJt3y8/master" --zk_session_timeout="10secs"
I0921 04:17:52.475055 28966 master.cpp:432] Master only allowing authenticated frameworks to register
I0921 04:17:52.475065 28966 master.cpp:446] Master only allowing authenticated agents to register
I0921 04:17:52.475071 28966 master.cpp:459] Master only allowing authenticated HTTP frameworks to register
I0921 04:17:52.475078 28966 credentials.hpp:37] Loading credentials for authentication from '/tmp/hJt3y8/credentials'
I0921 04:17:52.475370 28966 master.cpp:504] Using default 'crammd5' authenticator
I0921 04:17:52.475510 28966 http.cpp:883] Using default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0921 04:17:52.475670 28966 http.cpp:883] Using default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0921 04:17:52.475811 28966 http.cpp:883] Using default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0921 04:17:52.476033 28966 master.cpp:584] Authorization enabled
I0921 04:17:52.476243 28962 hierarchical.cpp:149] Initialized hierarchical allocator process
I0921 04:17:52.476261 28952 whitelist_watcher.cpp:77] No whitelist given
I0921 04:17:52.478655 28957 master.cpp:2013] Elected as the leading master!
I0921 04:17:52.478698 28957 master.cpp:1560] Recovering from registrar
I0921 04:17:52.478850 28951 registrar.cpp:329] Recovering registrar
I0921 04:17:52.545322 28963 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 71.731719ms
I0921 04:17:52.545414 28963 replica.cpp:320] Persisted replica status to STARTING
I0921 04:17:52.545828 28963 recover.cpp:477] Replica is in STARTING status
I0921 04:17:52.546953 28951 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from __req_res__(3010)@172.17.0.2:51750
I0921 04:17:52.547405 28958 recover.cpp:197] Received a recover response from a replica in STARTING status
I0921 04:17:52.547857 28961 recover.cpp:568] Updating replica status to VOTING
I0921 04:17:52.623605 28955 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 75.502866ms
I0921 04:17:52.623683 28955 replica.cpp:320] Persisted replica status to VOTING
I0921 04:17:52.623908 28966 recover.cpp:582] Successfully joined the Paxos group
I0921 04:17:52.624367 28966 recover.cpp:466] Recover process terminated
I0921 04:17:52.624753 28964 log.cpp:553] Attempting to start the writer
I0921 04:17:52.625964 28953 replica.cpp:493] Replica received implicit promise request from __req_res__(3011)@172.17.0.2:51750 with proposal 1
I0921 04:17:52.734971 28953 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 108.958888ms
I0921 04:17:52.735045 28953 replica.cpp:342] Persisted promised to 1
I0921 04:17:52.735785 28960 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0921 04:17:52.736977 28953 replica.cpp:388] Replica received explicit promise request from __req_res__(3012)@172.17.0.2:51750 for position 0 with proposal 2
I0921 04:17:52.835407 28953 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 98.374742ms
I0921 04:17:52.835491 28953 replica.cpp:708] Persisted action NOP at position 0
I0921 04:17:52.837040 28953 replica.cpp:537] Replica received write request for position 0 from __req_res__(3013)@172.17.0.2:51750
I0921 04:17:52.837108 28953 leveldb.cpp:436] Reading position from leveldb took 35710ns
Build timed out (after 180 minutes). Marking the build as failed.
Build was aborted
I0921 04:17:52.935015 28953 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 97.852878ms
I0921 04:17:52.935101 28953 replica.cpp:708] Persisted action NOP at position 0
I0921 04:17:52.935971 28964 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0921 04:17:53.083693 28964 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 147.668016ms
I0921 04:17:53.083786 28964 replica.cpp:708] Persisted action NOP at position 0
I0921 04:17:53.084779 28966 log.cpp:569] Writer started with ending position 0
I0921 04:17:53.086145 28964 leveldb.cpp:436] Reading position from leveldb took 58030ns
I0921 04:17:53.088309 28964 registrar.cpp:362] Successfully fetched the registry (0B) in 609.379072ms
I0921 04:17:53.088426 28964 registrar.cpp:461] Applied 1 operations in 23115ns; attempting to update the registry
I0921 04:17:53.089160 28966 log.cpp:577] Attempting to append 168 bytes to the log
I0921 04:17:53.089290 28965 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0921 04:17:53.090167 28957 replica.cpp:537] Replica received write request for position 1 from __req_res__(3014)@172.17.0.2:51750
I0921 04:17:53.194900 28957 leveldb.cpp:341] Persisting action (187 bytes) to leveldb took 104.595228ms
I0921 04:17:53.194998 28957 replica.cpp:708] Persisted action APPEND at position 1
I0921 04:17:53.196228 28966 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0