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 2017/11/20 01:23:11 UTC
Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4473
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4473/display/redirect?page=changes>
Changes:
[bmahler] Added a Future constructor for Try<Future<T>>.
------------------------------------------
[...truncated 3.17 MB...]
3: I1120 01:19:54.442893 17369 slave.cpp:4998] Forwarding the update TASK_RUNNING (UUID: de2978ca-2f47-4dbe-a309-96360d9fad76) for task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 to master@172.17.0.2:36246
3: I1120 01:19:54.443179 17369 slave.cpp:4892] Status update manager successfully handled status update TASK_RUNNING (UUID: de2978ca-2f47-4dbe-a309-96360d9fad76) for task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.443251 17369 slave.cpp:4908] Sending acknowledgement for status update TASK_RUNNING (UUID: de2978ca-2f47-4dbe-a309-96360d9fad76) for task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 to executor(4)@172.17.0.2:36246
3: I1120 01:19:54.443423 17364 master.cpp:7247] Status update TASK_RUNNING (UUID: de2978ca-2f47-4dbe-a309-96360d9fad76) for task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 from agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 at slave(48)@172.17.0.2:36246 (ef3e6d5c1e51)
3: I1120 01:19:54.443470 17359 exec.cpp:388] Executor received status update acknowledgement de2978ca-2f47-4dbe-a309-96360d9fad76 for task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.443492 17364 master.cpp:7309] Forwarding status update TASK_RUNNING (UUID: de2978ca-2f47-4dbe-a309-96360d9fad76) for task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.443706 17364 master.cpp:9502] Updating the state of task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
3: I1120 01:19:54.443951 17371 sched.cpp:1029] Scheduler::statusUpdate took 59896ns
3: I1120 01:19:54.444389 17366 master.cpp:5791] Processing ACKNOWLEDGE call de2978ca-2f47-4dbe-a309-96360d9fad76 for task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 (default) at scheduler-abd98832-286c-440a-ae3e-4fe9613cd230@172.17.0.2:36246 on agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0
3: I1120 01:19:54.444552 17366 master.cpp:1151] Master terminating
3: I1120 01:19:54.444767 17357 status_update_manager.cpp:395] Received status update acknowledgement (UUID: de2978ca-2f47-4dbe-a309-96360d9fad76) for task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: W1120 01:19:54.444687 17366 master.cpp:9582] Removing task 0 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":16.0},"type":"SCALAR"}] of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 on agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 at slave(48)@172.17.0.2:36246 (ef3e6d5c1e51) in non-removable state TASK_RUNNING
3: I1120 01:19:54.445087 17357 slave.cpp:3801] Status update manager successfully handled status update acknowledgement (UUID: de2978ca-2f47-4dbe-a309-96360d9fad76) for task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.445274 17355 hierarchical.cpp:633] Removed agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0
3: I1120 01:19:54.445467 17366 master.cpp:9625] Removing executor 'default' with resources [] of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 on agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 at slave(48)@172.17.0.2:36246 (ef3e6d5c1e51)
3: I1120 01:19:54.446218 17372 hierarchical.cpp:358] Removed framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.446455 17364 slave.cpp:5130] Got exited event for master@172.17.0.2:36246
3: W1120 01:19:54.446487 17364 slave.cpp:5135] Master disconnected! Waiting for a new master to be elected
3: I1120 01:19:54.452167 17350 cluster.cpp:162] Creating default 'local' authorizer
3: I1120 01:19:54.456352 17351 master.cpp:448] Master 120b9d3b-32a5-4128-bed0-4e918b650a76 (ef3e6d5c1e51) started on 172.17.0.2:36246
3: I1120 01:19:54.456378 17351 master.cpp:450] 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/VGD2kD/credentials" --filter_gpu_resources="true" --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" --max_unreachable_tasks_per_framework="1000" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --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="/usr/local/share/mesos/webui" --work_dir="/tmp/VGD2kD/master" --zk_session_timeout="10secs"
3: I1120 01:19:54.456692 17351 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1120 01:19:54.456701 17351 master.cpp:505] Master only allowing authenticated agents to register
3: I1120 01:19:54.456704 17351 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1120 01:19:54.456710 17351 credentials.hpp:37] Loading credentials for authentication from '/tmp/VGD2kD/credentials'
3: I1120 01:19:54.456993 17351 master.cpp:555] Using default 'crammd5' authenticator
3: I1120 01:19:54.457142 17351 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1120 01:19:54.457296 17351 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1120 01:19:54.457432 17351 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1120 01:19:54.457553 17351 master.cpp:634] Authorization enabled
3: I1120 01:19:54.457696 17363 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1120 01:19:54.457764 17356 whitelist_watcher.cpp:77] No whitelist given
3: I1120 01:19:54.461360 17373 master.cpp:2213] Elected as the leading master!
3: I1120 01:19:54.461390 17373 master.cpp:1693] Recovering from registrar
3: I1120 01:19:54.461503 17371 registrar.cpp:347] Recovering registrar
3: I1120 01:19:54.462060 17371 registrar.cpp:391] Successfully fetched the registry (0B) in 517888ns
3: I1120 01:19:54.462154 17371 registrar.cpp:495] Applied 1 operations in 26237ns; attempting to update the registry
3: I1120 01:19:54.462659 17371 registrar.cpp:552] Successfully updated the registry in 456704ns
3: I1120 01:19:54.462779 17371 registrar.cpp:424] Successfully recovered registrar
3: I1120 01:19:54.463153 17363 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: I1120 01:19:54.463145 17365 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1120 01:19:54.463969 17356 status_update_manager.cpp:177] Pausing sending status updates
3: I1120 01:19:54.463987 17361 slave.cpp:1007] New master detected at master@172.17.0.2:36246
3: I1120 01:19:54.464140 17361 slave.cpp:1042] Detecting new master
3: I1120 01:19:54.466616 17359 slave.cpp:1069] Authenticating with master master@172.17.0.2:36246
3: I1120 01:19:54.466712 17359 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1120 01:19:54.467034 17352 authenticatee.cpp:121] Creating new client SASL connection
3: I1120 01:19:54.467422 17372 master.cpp:8285] Authenticating slave(48)@172.17.0.2:36246
3: I1120 01:19:54.467561 17358 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(107)@172.17.0.2:36246
3: I1120 01:19:54.467814 17373 authenticator.cpp:98] Creating new server SASL connection
3: I1120 01:19:54.468078 17366 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1120 01:19:54.468106 17366 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1120 01:19:54.468241 17364 authenticator.cpp:204] Received SASL authentication start
3: I1120 01:19:54.468300 17364 authenticator.cpp:326] Authentication requires more steps
3: I1120 01:19:54.468416 17368 authenticatee.cpp:259] Received SASL authentication step
3: I1120 01:19:54.468577 17353 authenticator.cpp:232] Received SASL authentication step
3: I1120 01:19:54.468611 17353 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ef3e6d5c1e51' server FQDN: 'ef3e6d5c1e51' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1120 01:19:54.468622 17353 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1120 01:19:54.468658 17353 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1120 01:19:54.468684 17353 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ef3e6d5c1e51' server FQDN: 'ef3e6d5c1e51' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1120 01:19:54.468693 17353 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1120 01:19:54.468699 17353 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1120 01:19:54.468719 17353 authenticator.cpp:318] Authentication success
3: I1120 01:19:54.468894 17362 authenticatee.cpp:299] Authentication success
3: I1120 01:19:54.468971 17360 master.cpp:8315] Successfully authenticated principal 'test-principal' at slave(48)@172.17.0.2:36246
3: I1120 01:19:54.469023 17371 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(107)@172.17.0.2:36246
3: I1120 01:19:54.469280 17362 slave.cpp:1161] Successfully authenticated with master master@172.17.0.2:36246
3: I1120 01:19:54.469904 17362 slave.cpp:1682] Will retry registration in 9.633259ms if necessary
3: I1120 01:19:54.470635 17365 master.cpp:6350] Received re-register agent message from agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 at slave(48)@172.17.0.2:36246 (ef3e6d5c1e51)
3: I1120 01:19:54.470897 17365 master.cpp:3870] Authorizing agent with principal 'test-principal'
3: I1120 01:19:54.471434 17367 master.cpp:6419] Authorized re-registration of agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 at slave(48)@172.17.0.2:36246 (ef3e6d5c1e51)
3: I1120 01:19:54.471511 17367 master.cpp:6599] Re-registering agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 at slave(48)@172.17.0.2:36246 (ef3e6d5c1e51)
3: W1120 01:19:54.471983 17351 master.hpp:2270] Allowing UNKNOWN agent to reregister: hostname: "ef3e6d5c1e51"
3: resources {
3: name: "cpus"
3: type: SCALAR
3: scalar {
3: value: 2
3: }
3: role: "*"
3: }
3: resources {
3: name: "mem"
3: type: SCALAR
3: scalar {
3: value: 1024
3: }
3: role: "*"
3: }
3: resources {
3: name: "disk"
3: type: SCALAR
3: scalar {
3: value: 1024
3: }
3: role: "*"
3: }
3: resources {
3: name: "ports"
3: type: RANGES
3: ranges {
3: range {
3: begin: 31000
3: end: 32000
3: }
3: }
3: role: "*"
3: }
3: id {
3: value: "2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0"
3: }
3: checkpoint: true
3: port: 36246
3: I1120 01:19:54.472280 17351 registrar.cpp:495] Applied 1 operations in 327520ns; attempting to update the registry
3: I1120 01:19:54.473042 17369 registrar.cpp:552] Successfully updated the registry in 691200ns
3: I1120 01:19:54.473544 17372 master.cpp:6668] Re-admitted agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 at slave(48)@172.17.0.2:36246 (ef3e6d5c1e51)
3: I1120 01:19:54.474344 17372 master.cpp:10770] Adding task 0 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":16.0},"type":"SCALAR"}] on agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 at slave(48)@172.17.0.2:36246 (ef3e6d5c1e51)
3: I1120 01:19:54.475162 17372 master.cpp:6846] Re-registered agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 at slave(48)@172.17.0.2:36246 (ef3e6d5c1e51) with [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1120 01:19:54.475545 17372 master.cpp:6929] Recovering framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 from re-registering agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 at slave(48)@172.17.0.2:36246 (ef3e6d5c1e51)
3: I1120 01:19:54.475613 17373 slave.cpp:1340] Re-registered with master master@172.17.0.2:36246
3: I1120 01:19:54.475754 17366 hierarchical.cpp:600] Added agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 (ef3e6d5c1e51) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: cpus(allocated: *):1; mem(allocated: *):16)
3: I1120 01:19:54.475819 17373 slave.cpp:1397] Forwarding total oversubscribed resources {}
3: I1120 01:19:54.475792 17354 status_update_manager.cpp:184] Resuming sending status updates
3: I1120 01:19:54.476279 17366 hierarchical.cpp:1457] Performed allocation for 1 agents in 234519ns
3: I1120 01:19:54.476560 17374 slave.cpp:5130] Got exited event for executor(4)@172.17.0.2:36246
3: I1120 01:19:54.476558 17372 master.cpp:7064] Received update of agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 at slave(48)@172.17.0.2:36246 (ef3e6d5c1e51) with total oversubscribed resources {}
3: I1120 01:19:54.476794 17361 slave.cpp:5539] Executor 'default' of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 exited with status 0
3: I1120 01:19:54.476826 17372 master.cpp:7082] Ignoring update on agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 at slave(48)@172.17.0.2:36246 (ef3e6d5c1e51) as it reports no changes
3: I1120 01:19:54.476953 17361 slave.cpp:4517] Handling status update TASK_FAILED (UUID: 26f4f9b4-62b9-4485-8382-c7922ec98bcd) for task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 from @0.0.0.0:0
3: I1120 01:19:54.477411 17366 hierarchical.cpp:306] Added framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.477478 17366 hierarchical.cpp:419] Deactivated framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.477558 17369 master.cpp:7459] Executor 'default' of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 on agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 at slave(48)@172.17.0.2:36246 (ef3e6d5c1e51): exited with status 0
3: I1120 01:19:54.477641 17369 master.cpp:9625] Removing executor 'default' with resources [] of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 on agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 at slave(48)@172.17.0.2:36246 (ef3e6d5c1e51)
3: W1120 01:19:54.477869 17369 master.cpp:7471] Not forwarding exited executor message for executor 'default' of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 on agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 at slave(48)@172.17.0.2:36246 (ef3e6d5c1e51) because the framework is disconnected
3: I1120 01:19:54.478091 17365 status_update_manager.cpp:323] Received status update TASK_FAILED (UUID: 26f4f9b4-62b9-4485-8382-c7922ec98bcd) for task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.478145 17371 sched.cpp:330] Scheduler::disconnected took 18925ns
3: I1120 01:19:54.478168 17371 sched.cpp:336] New master detected at master@172.17.0.2:36246
3: I1120 01:19:54.478240 17365 status_update_manager.cpp:377] Forwarding update TASK_FAILED (UUID: 26f4f9b4-62b9-4485-8382-c7922ec98bcd) for task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 to the agent
3: I1120 01:19:54.478302 17371 sched.cpp:396] Authenticating with master master@172.17.0.2:36246
3: I1120 01:19:54.478327 17371 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1120 01:19:54.478437 17374 slave.cpp:4998] Forwarding the update TASK_FAILED (UUID: 26f4f9b4-62b9-4485-8382-c7922ec98bcd) for task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 to master@172.17.0.2:36246
3: I1120 01:19:54.478600 17365 authenticatee.cpp:121] Creating new client SASL connection
3: I1120 01:19:54.478679 17374 slave.cpp:4892] Status update manager successfully handled status update TASK_FAILED (UUID: 26f4f9b4-62b9-4485-8382-c7922ec98bcd) for task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.478870 17360 master.cpp:8285] Authenticating scheduler-abd98832-286c-440a-ae3e-4fe9613cd230@172.17.0.2:36246
3: I1120 01:19:54.479043 17372 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(108)@172.17.0.2:36246
3: I1120 01:19:54.479394 17356 authenticator.cpp:98] Creating new server SASL connection
3: I1120 01:19:54.479706 17361 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1120 01:19:54.479735 17361 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1120 01:19:54.479852 17358 authenticator.cpp:204] Received SASL authentication start
3: I1120 01:19:54.479903 17358 authenticator.cpp:326] Authentication requires more steps
3: I1120 01:19:54.480022 17353 authenticatee.cpp:259] Received SASL authentication step
3: I1120 01:19:54.480157 17364 authenticator.cpp:232] Received SASL authentication step
3: I1120 01:19:54.480207 17364 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ef3e6d5c1e51' server FQDN: 'ef3e6d5c1e51' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1120 01:19:54.480237 17364 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1120 01:19:54.480262 17364 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1120 01:19:54.480283 17364 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ef3e6d5c1e51' server FQDN: 'ef3e6d5c1e51' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1120 01:19:54.480293 17364 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1120 01:19:54.480298 17364 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1120 01:19:54.480310 17364 authenticator.cpp:318] Authentication success
3: I1120 01:19:54.480446 17366 authenticatee.cpp:299] Authentication success
3: I1120 01:19:54.480537 17368 master.cpp:8315] Successfully authenticated principal 'test-principal' at scheduler-abd98832-286c-440a-ae3e-4fe9613cd230@172.17.0.2:36246
3: I1120 01:19:54.480597 17370 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(108)@172.17.0.2:36246
3: I1120 01:19:54.480813 17366 sched.cpp:502] Successfully authenticated with master master@172.17.0.2:36246
3: I1120 01:19:54.480844 17366 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.2:36246
3: I1120 01:19:54.481005 17366 sched.cpp:857] Will retry registration in 1.262061411secs if necessary
3: I1120 01:19:54.481261 17355 master.cpp:2961] Received SUBSCRIBE call for framework 'default' at scheduler-abd98832-286c-440a-ae3e-4fe9613cd230@172.17.0.2:36246
3: I1120 01:19:54.481371 17355 master.cpp:2278] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
3: I1120 01:19:54.481863 17367 master.cpp:3041] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1120 01:19:54.481936 17367 master.cpp:6967] Updating info for framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.482264 17352 hierarchical.cpp:385] Activated framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.482537 17351 sched.cpp:751] Framework registered with 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.482561 17374 slave.cpp:3438] Updating info for framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 with pid updated to scheduler-abd98832-286c-440a-ae3e-4fe9613cd230@172.17.0.2:36246
3: I1120 01:19:54.482653 17351 sched.cpp:765] Scheduler::registered took 73136ns
3: I1120 01:19:54.482669 17365 status_update_manager.cpp:184] Resuming sending status updates
3: W1120 01:19:54.482702 17365 status_update_manager.cpp:191] Resending status update TASK_FAILED (UUID: 26f4f9b4-62b9-4485-8382-c7922ec98bcd) for task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.482738 17365 status_update_manager.cpp:377] Forwarding update TASK_FAILED (UUID: 26f4f9b4-62b9-4485-8382-c7922ec98bcd) for task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 to the agent
3: I1120 01:19:54.482960 17356 slave.cpp:4998] Forwarding the update TASK_FAILED (UUID: 26f4f9b4-62b9-4485-8382-c7922ec98bcd) for task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 to master@172.17.0.2:36246
3: I1120 01:19:54.483047 17350 sched.cpp:2009] Asked to stop the driver
3: I1120 01:19:54.483168 17364 sched.cpp:1191] Stopping framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.483398 17359 master.cpp:8792] Processing TEARDOWN call for framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 (default) at scheduler-abd98832-286c-440a-ae3e-4fe9613cd230@172.17.0.2:36246
3: I1120 01:19:54.483431 17359 master.cpp:8804] Removing framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 (default) at scheduler-abd98832-286c-440a-ae3e-4fe9613cd230@172.17.0.2:36246
3: I1120 01:19:54.483444 17359 master.cpp:3331] Deactivating framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 (default) at scheduler-abd98832-286c-440a-ae3e-4fe9613cd230@172.17.0.2:36246
3: I1120 01:19:54.483594 17359 master.cpp:9502] Updating the state of task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
3: I1120 01:19:54.483613 17368 slave.cpp:3267] Asked to shut down framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 by master@172.17.0.2:36246
3: I1120 01:19:54.483649 17368 slave.cpp:3292] Shutting down framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.483705 17368 slave.cpp:5643] Cleaning up executor 'default' of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 at executor(4)@172.17.0.2:36246
3: I1120 01:19:54.484001 17363 gc.cpp:90] Scheduling '/tmp/FaultToleranceTest_ReregisterFrameworkExitedExecutor_ccqohf/slaves/2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0/frameworks/2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000/executors/default/runs/302bc810-15aa-4ccf-8e7d-dc7bf6d2c97b' for gc 6.99999439975704days in the future
3: I1120 01:19:54.484069 17352 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.595827ms
3: I1120 01:19:54.484114 17368 slave.cpp:5750] Cleaning up framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.484045 17359 master.cpp:9596] Removing task 0 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":16.0},"type":"SCALAR"}] of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 on agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 at slave(48)@172.17.0.2:36246 (ef3e6d5c1e51)
3: I1120 01:19:54.484247 17352 hierarchical.cpp:419] Deactivated framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.484295 17373 status_update_manager.cpp:285] Closing status update streams for framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.484346 17373 status_update_manager.cpp:531] Cleaning up status update stream for task 0 of framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.484370 17363 gc.cpp:90] Scheduling '/tmp/FaultToleranceTest_ReregisterFrameworkExitedExecutor_ccqohf/slaves/2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0/frameworks/2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000/executors/default' for gc 6.99999439768593days in the future
3: I1120 01:19:54.484606 17363 gc.cpp:90] Scheduling '/tmp/FaultToleranceTest_ReregisterFrameworkExitedExecutor_ccqohf/slaves/2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0/frameworks/2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000' for gc 6.99999439525333days in the future
3: W1120 01:19:54.484817 17359 master.cpp:7961] Master returning resources offered to framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000 because the framework has terminated or is inactive
3: I1120 01:19:54.484928 17352 hierarchical.cpp:1132] Recovered cpus(allocated: *):1; mem(allocated: *):16 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: cpus(allocated: *):1; mem(allocated: *):1008; disk(allocated: *):1024; ports(allocated: *):[31000-32000]) on agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 from framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.485225 17369 slave.cpp:883] Agent terminating
3: I1120 01:19:54.485388 17370 master.cpp:1309] Agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 at slave(48)@172.17.0.2:36246 (ef3e6d5c1e51) disconnected
3: I1120 01:19:54.485410 17370 master.cpp:3368] Disconnecting agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 at slave(48)@172.17.0.2:36246 (ef3e6d5c1e51)
3: I1120 01:19:54.485453 17370 master.cpp:3387] Deactivating agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 at slave(48)@172.17.0.2:36246 (ef3e6d5c1e51)
3: I1120 01:19:54.486171 17352 hierarchical.cpp:358] Removed framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.486536 17352 hierarchical.cpp:1132] Recovered cpus(allocated: *):1; mem(allocated: *):1008; disk(allocated: *):1024; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: {}) on agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 from framework 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-0000
3: I1120 01:19:54.486677 17352 hierarchical.cpp:697] Agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0 deactivated
3: I1120 01:19:54.490701 17350 master.cpp:1151] Master terminating
3: I1120 01:19:54.491350 17365 hierarchical.cpp:633] Removed agent 2ac5ea8d-b229-4965-b7fd-6f024db93ea5-S0
3: [ OK ] FaultToleranceTest.ReregisterFrameworkExitedExecutor (119 ms)
3: [ RUN ] FaultToleranceTest.ForwardStatusUpdateUnknownExecutor
3: I1120 01:19:54.500409 17350 cluster.cpp:162] Creating default 'local' authorizer
3: I1120 01:19:54.504853 17354 master.cpp:448] Master 084a8b9e-a316-4d37-9e86-c60375b3c241 (ef3e6d5c1e51) started on 172.17.0.2:36246
3: I1120 01:19:54.504884 17354 master.cpp:450] 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/51fRmH/credentials" --filter_gpu_resources="true" --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" --max_unreachable_tasks_per_framework="1000" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --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="/usr/local/share/mesos/webui" --work_dir="/tmp/51fRmH/master" --zk_session_timeout="10secs"
3: I1120 01:19:54.505308 17354 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1120 01:19:54.505321 17354 master.cpp:505] Master only allowing authenticated agents to register
3: I1120 01:19:54.505327 17354 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1120 01:19:54.505336 17354 credentials.hpp:37] Loading credentials for authentication from '/tmp/51fRmH/credentials'
3: I1120 01:19:54.505754 17354 master.cpp:555] Using default 'crammd5' authenticator
3: I1120 01:19:54.505969 17354 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1120 01:19:54.506198 17354 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1120 01:19:54.506405 17354 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1120 01:19:54.506594 17354 master.cpp:634] Authorization enabled
3: I1120 01:19:54.506777 17373 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1120 01:19:54.506814 17352 whitelist_watcher.cpp:77] No whitelist given
3: I1120 01:19:54.510653 17372 master.cpp:2213] Elected as the leading master!
3: I1120 01:19:54.510706 17372 master.cpp:1693] Recovering from registrar
3: I1120 01:19:54.510902 17359 registrar.cpp:347] Recovering registrar
3: I1120 01:19:54.511620 17359 registrar.cpp:391] Successfully fetched the registry (0B) in 662016ns
3: I1120 01:19:54.511746 17359 registrar.cpp:495] Applied 1 operations in 33034ns; attempting to update the registry
3: I1120 01:19:54.512501 17359 registrar.cpp:552] Successfully updated the registry in 690176ns
3: I1120 01:19:54.512653 17359 registrar.cpp:424] Successfully recovered registrar
3: I1120 01:19:54.513139 17371 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1120 01:19:54.513212 17366 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: W1120 01:19:54.520340 17350 process.cpp:3185] Attempted to spawn already running process files@172.17.0.2:36246
3: I1120 01:19:54.520833 17350 cluster.cpp:448] Creating default 'local' authorizer
3: I1120 01:19:54.524412 17356 slave.cpp:262] Mesos agent started on (49)@172.17.0.2:36246
3: I1120 01:19:54.524441 17356 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/FaultToleranceTest_ForwardStatusUpdateUnknownExecutor_j3A6NV/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/FaultToleranceTest_ForwardStatusUpdateUnknownExecutor_j3A6NV/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/FaultToleranceTest_ForwardStatusUpdateUnknownExecutor_j3A6NV/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/FaultToleranceTest_ForwardStatusUpdateUnknownExecutor_j3A6NV/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/FaultToleranceTest_ForwardStatusUpdateUnknownExecutor_j3A6NV/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/FaultToleranceTest_ForwardStatusUpdateUnknownExecutor_j3A6NV" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/FaultToleranceTest_ForwardStatusUpdateUnknownExecutor_a35sAj" --zk_session_timeout="10secs"
3: I1120 01:19:54.525048 17356 credentials.hpp:86] Loading credential for authentication from '/tmp/FaultToleranceTest_ForwardStatusUpdateUnknownExecutor_j3A6NV/credential'
3: I1120 01:19:54.525264 17356 slave.cpp:295] Agent using credential for: test-principal
3: I1120 01:19:54.525291 17356 credentials.hpp:37] Loading credentials for authentication from '/tmp/FaultToleranceTest_ForwardStatusUpdateUnknownExecutor_j3A6NV/http_credentials'
3: W1120 01:19:54.525300 17350 process.cpp:3185] Attempted to spawn already running process version@172.17.0.2:36246
3: I1120 01:19:54.525609 17356 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1120 01:19:54.525805 17356 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1120 01:19:54.526849 17350 sched.cpp:232] Version: 1.5.0
3: I1120 01:19:54.527669 17358 sched.cpp:336] New master detected at master@172.17.0.2:36246
3: I1120 01:19:54.527832 17358 sched.cpp:396] Authenticating with master master@172.17.0.2:36246
3: I1120 01:19:54.527858 17358 sched.cpp:403] Using default CRAM-MD5 authenticatee
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1511138424-1892
Error response from daemon: conflict: unable to remove repository reference "mesos-1511138424-1892" (must force) - container ef3e6d5c1e51 is using its referenced image afef040fd12f
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4476
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4476/display/redirect?page=changes>
Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4475
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4475/display/redirect>
------------------------------------------
[...truncated 31.75 MB...]
3: I1120 03:37:43.050403 17293 master.cpp:505] Master only allowing authenticated agents to register
3: I1120 03:37:43.050412 17293 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1120 03:37:43.050423 17293 credentials.hpp:37] Loading credentials for authentication from '/tmp/jsqKgg/credentials'
3: I1120 03:37:43.050833 17293 master.cpp:555] Using default 'crammd5' authenticator
3: I1120 03:37:43.051036 17293 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1120 03:37:43.051252 17293 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1120 03:37:43.051440 17293 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1120 03:37:43.051625 17293 master.cpp:634] Authorization enabled
3: W1120 03:37:43.051645 17293 master.cpp:697] The '--roles' flag is deprecated. This flag will be removed in the future. See the Mesos 0.27 upgrade notes for more information
3: I1120 03:37:43.051916 17289 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1120 03:37:43.051990 17302 whitelist_watcher.cpp:77] No whitelist given
3: I1120 03:37:43.055193 17300 master.cpp:2213] Elected as the leading master!
3: I1120 03:37:43.055223 17300 master.cpp:1693] Recovering from registrar
3: I1120 03:37:43.055425 17292 registrar.cpp:347] Recovering registrar
3: I1120 03:37:43.055965 17292 registrar.cpp:391] Successfully fetched the registry (0B) in 0ns
3: I1120 03:37:43.056044 17292 registrar.cpp:495] Applied 1 operations in 20328ns; attempting to update the registry
3: I1120 03:37:43.056522 17292 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1120 03:37:43.056622 17292 registrar.cpp:424] Successfully recovered registrar
3: I1120 03:37:43.057080 17294 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1120 03:37:43.057092 17296 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: W1120 03:37:43.061714 17287 process.cpp:3185] Attempted to spawn already running process files@172.17.0.2:60428
3: I1120 03:37:43.062501 17287 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1120 03:37:43.062937 17287 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1120 03:37:43.063040 17287 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1120 03:37:43.063094 17287 provisioner.cpp:255] Using default backend 'copy'
3: I1120 03:37:43.064715 17287 cluster.cpp:448] Creating default 'local' authorizer
3: I1120 03:37:43.066646 17303 slave.cpp:262] Mesos agent started on (883)@172.17.0.2:60428
3: W1120 03:37:43.067044 17287 process.cpp:3185] Attempted to spawn already running process version@172.17.0.2:60428
3: I1120 03:37:43.066668 17303 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_2ww4Fa/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_2ww4Fa/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_2ww4Fa/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_2ww4Fa/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_2ww4Fa/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="[{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":2048.0},"type":"SCALAR"},{"disk":{"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT\/disk1"},"type":"PATH"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"},{"disk":{"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT\/disk2"},"type":"PATH"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_2ww4Fa" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vbNccx" --zk_session_timeout="10secs"
3: I1120 03:37:43.067185 17303 credentials.hpp:86] Loading credential for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_2ww4Fa/credential'
3: I1120 03:37:43.067373 17303 slave.cpp:295] Agent using credential for: test-principal
3: I1120 03:37:43.067394 17303 credentials.hpp:37] Loading credentials for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_2ww4Fa/http_credentials'
3: I1120 03:37:43.067673 17303 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1120 03:37:43.067842 17287 sched.cpp:232] Version: 1.5.0
3: I1120 03:37:43.067862 17303 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1120 03:37:43.068323 17293 sched.cpp:336] New master detected at master@172.17.0.2:60428
3: I1120 03:37:43.068469 17293 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1120 03:37:43.068495 17293 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.2:60428
3: I1120 03:37:43.068650 17293 sched.cpp:857] Will retry registration in 18.804584ms if necessary
3: I1120 03:37:43.068897 17288 master.cpp:2961] Received SUBSCRIBE call for framework 'default' at scheduler-c36cc707-0b2e-4c20-a5dc-247f129c584d@172.17.0.2:60428
3: I1120 03:37:43.068992 17288 master.cpp:2278] Authorizing framework principal 'test-principal' to receive offers for roles '{ default-role }'
3: I1120 03:37:43.069440 17297 master.cpp:3041] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1120 03:37:43.069980 17297 sched.cpp:751] Framework registered with 94078a06-852d-40e4-96b9-3c47da182e0b-0000
3: I1120 03:37:43.070016 17297 sched.cpp:765] Scheduler::registered took 17953ns
3: I1120 03:37:43.070307 17289 hierarchical.cpp:306] Added framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000
3: I1120 03:37:43.070546 17289 hierarchical.cpp:1457] Performed allocation for 0 agents in 100457ns
3: I1120 03:37:43.072465 17303 slave.cpp:593] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":2048.0},"type":"SCALAR"},{"disk":{"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT\/disk1"},"type":"PATH"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"},{"disk":{"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT\/disk2"},"type":"PATH"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1120 03:37:43.073029 17303 slave.cpp:601] Agent attributes: [ ]
3: I1120 03:37:43.073040 17303 slave.cpp:610] Agent hostname: a89a9485b29e
3: I1120 03:37:43.073333 17290 status_update_manager.cpp:177] Pausing sending status updates
3: I1120 03:37:43.074832 17300 state.cpp:64] Recovering state from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vbNccx/meta'
3: I1120 03:37:43.075152 17300 status_update_manager.cpp:203] Recovering status update manager
3: I1120 03:37:43.075328 17295 containerizer.cpp:662] Recovering containerizer
3: I1120 03:37:43.076982 17298 provisioner.cpp:416] Provisioner recovery complete
3: I1120 03:37:43.077401 17293 slave.cpp:6441] Finished recovery
3: I1120 03:37:43.078228 17302 slave.cpp:1007] New master detected at master@172.17.0.2:60428
3: I1120 03:37:43.078253 17299 status_update_manager.cpp:177] Pausing sending status updates
3: I1120 03:37:43.078294 17302 slave.cpp:1042] Detecting new master
3: I1120 03:37:43.079953 17295 slave.cpp:1069] Authenticating with master master@172.17.0.2:60428
3: I1120 03:37:43.080029 17295 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1120 03:37:43.080274 17292 authenticatee.cpp:121] Creating new client SASL connection
3: I1120 03:37:43.080444 17291 hierarchical.cpp:1457] Performed allocation for 0 agents in 64556ns
3: I1120 03:37:43.080529 17301 master.cpp:8285] Authenticating slave(883)@172.17.0.2:60428
3: I1120 03:37:43.080657 17288 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1577)@172.17.0.2:60428
3: I1120 03:37:43.080915 17298 authenticator.cpp:98] Creating new server SASL connection
3: I1120 03:37:43.081126 17300 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1120 03:37:43.081146 17300 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1120 03:37:43.081250 17300 authenticator.cpp:204] Received SASL authentication start
3: I1120 03:37:43.081306 17300 authenticator.cpp:326] Authentication requires more steps
3: I1120 03:37:43.081413 17300 authenticatee.cpp:259] Received SASL authentication step
3: I1120 03:37:43.081527 17296 authenticator.cpp:232] Received SASL authentication step
3: I1120 03:37:43.081554 17296 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'a89a9485b29e' server FQDN: 'a89a9485b29e' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1120 03:37:43.081570 17296 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1120 03:37:43.081601 17296 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1120 03:37:43.081622 17296 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'a89a9485b29e' server FQDN: 'a89a9485b29e' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1120 03:37:43.081634 17296 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1120 03:37:43.081640 17296 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1120 03:37:43.081650 17296 authenticator.cpp:318] Authentication success
3: I1120 03:37:43.081727 17299 authenticatee.cpp:299] Authentication success
3: I1120 03:37:43.081796 17302 master.cpp:8315] Successfully authenticated principal 'test-principal' at slave(883)@172.17.0.2:60428
3: I1120 03:37:43.081867 17289 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1577)@172.17.0.2:60428
3: I1120 03:37:43.082022 17299 slave.cpp:1161] Successfully authenticated with master master@172.17.0.2:60428
3: I1120 03:37:43.082243 17299 slave.cpp:1682] Will retry registration in 14.944577ms if necessary
3: I1120 03:37:43.082547 17291 master.cpp:6032] Received register agent message from slave(883)@172.17.0.2:60428 (a89a9485b29e)
3: I1120 03:37:43.082684 17291 master.cpp:3870] Authorizing agent with principal 'test-principal'
3: I1120 03:37:43.083058 17288 master.cpp:6092] Authorized registration of agent at slave(883)@172.17.0.2:60428 (a89a9485b29e)
3: I1120 03:37:43.083184 17288 master.cpp:6185] Registering agent at slave(883)@172.17.0.2:60428 (a89a9485b29e) with id 94078a06-852d-40e4-96b9-3c47da182e0b-S0
3: I1120 03:37:43.083604 17298 registrar.cpp:495] Applied 1 operations in 58420ns; attempting to update the registry
3: I1120 03:37:43.084154 17297 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1120 03:37:43.084347 17302 master.cpp:6232] Admitted agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 at slave(883)@172.17.0.2:60428 (a89a9485b29e)
3: I1120 03:37:43.085171 17303 slave.cpp:1207] Registered with master master@172.17.0.2:60428; given agent ID 94078a06-852d-40e4-96b9-3c47da182e0b-S0
3: I1120 03:37:43.085311 17289 status_update_manager.cpp:184] Resuming sending status updates
3: I1120 03:37:43.085021 17302 master.cpp:6263] Registered agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 at slave(883)@172.17.0.2:60428 (a89a9485b29e) with [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":2048.0},"type":"SCALAR"},{"disk":{"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT\/disk1"},"type":"PATH"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"},{"disk":{"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT\/disk2"},"type":"PATH"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1120 03:37:43.085455 17296 hierarchical.cpp:600] Added agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 (a89a9485b29e) with cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk2]:2048; ports:[31000-32000] (allocated: {})
3: I1120 03:37:43.085544 17303 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vbNccx/meta/slaves/94078a06-852d-40e4-96b9-3c47da182e0b-S0/slave.info'
3: I1120 03:37:43.086138 17303 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: I1120 03:37:43.086352 17299 master.cpp:7064] Received update of agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 at slave(883)@172.17.0.2:60428 (a89a9485b29e) with total oversubscribed resources {}
3: I1120 03:37:43.086652 17299 master.cpp:7082] Ignoring update on agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 at slave(883)@172.17.0.2:60428 (a89a9485b29e) as it reports no changes
3: I1120 03:37:43.087182 17296 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.575666ms
3: I1120 03:37:43.088340 17291 master.cpp:8115] Sending 1 offers to framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000 (default) at scheduler-c36cc707-0b2e-4c20-a5dc-247f129c584d@172.17.0.2:60428
3: I1120 03:37:43.088918 17301 sched.cpp:921] Scheduler::resourceOffers took 91097ns
3: I1120 03:37:43.091298 17290 master.cpp:10024] Removing offer 94078a06-852d-40e4-96b9-3c47da182e0b-O0
3: I1120 03:37:43.091449 17290 master.cpp:4228] Processing ACCEPT call for offers: [ 94078a06-852d-40e4-96b9-3c47da182e0b-O0 ] on agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 at slave(883)@172.17.0.2:60428 (a89a9485b29e) for framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000 (default) at scheduler-c36cc707-0b2e-4c20-a5dc-247f129c584d@172.17.0.2:60428
3: I1120 03:37:43.091631 17290 master.cpp:3790] Authorizing principal 'test-principal' to create volumes '[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: W1120 03:37:43.092762 17297 master.cpp:2363] Dropping CREATE offer operation from framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000 (default) at scheduler-c36cc707-0b2e-4c20-a5dc-247f129c584d@172.17.0.2:60428: Not authorized to create persistent volumes as 'test-principal'
3: I1120 03:37:43.094017 17297 hierarchical.cpp:1132] Recovered cpus(allocated: default-role):2; mem(allocated: default-role):2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk2]:2048; ports:[31000-32000], allocated: {}) on agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 from framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000
3: I1120 03:37:43.097038 17302 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.319361ms
3: I1120 03:37:43.097961 17303 master.cpp:8115] Sending 1 offers to framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000 (default) at scheduler-c36cc707-0b2e-4c20-a5dc-247f129c584d@172.17.0.2:60428
3: I1120 03:37:43.098467 17299 sched.cpp:921] Scheduler::resourceOffers took 82938ns
3: W1120 03:37:43.099026 17287 process.cpp:3185] Attempted to spawn already running process version@172.17.0.2:60428
3: I1120 03:37:43.099202 17291 master.cpp:5432] Processing DECLINE call for offers: [ 94078a06-852d-40e4-96b9-3c47da182e0b-O1 ] for framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000 (default) at scheduler-c36cc707-0b2e-4c20-a5dc-247f129c584d@172.17.0.2:60428
3: I1120 03:37:43.099658 17287 sched.cpp:232] Version: 1.5.0
3: I1120 03:37:43.100162 17290 sched.cpp:336] New master detected at master@172.17.0.2:60428
3: I1120 03:37:43.100178 17291 master.cpp:10024] Removing offer 94078a06-852d-40e4-96b9-3c47da182e0b-O1
3: I1120 03:37:43.100273 17290 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1120 03:37:43.100289 17290 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.2:60428
3: I1120 03:37:43.100309 17291 master.cpp:3471] Processing SUPPRESS call for framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000 (default) at scheduler-c36cc707-0b2e-4c20-a5dc-247f129c584d@172.17.0.2:60428
3: I1120 03:37:43.100402 17290 sched.cpp:857] Will retry registration in 1.812170919secs if necessary
3: I1120 03:37:43.100533 17300 master.cpp:2961] Received SUBSCRIBE call for framework 'creator-framework' at scheduler-4dfb3f47-3719-47ae-957b-737f48a4c053@172.17.0.2:60428
3: I1120 03:37:43.100608 17300 master.cpp:2278] Authorizing framework principal 'creator-principal' to receive offers for roles '{ default-role }'
3: I1120 03:37:43.100903 17288 hierarchical.cpp:1132] Recovered cpus(allocated: default-role):2; mem(allocated: default-role):2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk2]:2048; ports:[31000-32000], allocated: {}) on agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 from framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000
3: I1120 03:37:43.101056 17288 hierarchical.cpp:1244] Suppressed offers for roles { default-role } of framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000
3: I1120 03:37:43.101084 17297 master.cpp:3041] Subscribing framework creator-framework with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1120 03:37:43.101510 17289 hierarchical.cpp:306] Added framework 94078a06-852d-40e4-96b9-3c47da182e0b-0001
3: I1120 03:37:43.101582 17297 sched.cpp:751] Framework registered with 94078a06-852d-40e4-96b9-3c47da182e0b-0001
3: I1120 03:37:43.101620 17297 sched.cpp:765] Scheduler::registered took 15948ns
3: I1120 03:37:43.103593 17289 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.920544ms
3: I1120 03:37:43.104329 17299 master.cpp:8115] Sending 1 offers to framework 94078a06-852d-40e4-96b9-3c47da182e0b-0001 (creator-framework) at scheduler-4dfb3f47-3719-47ae-957b-737f48a4c053@172.17.0.2:60428
3: I1120 03:37:43.104771 17296 sched.cpp:921] Scheduler::resourceOffers took 81256ns
3: I1120 03:37:43.106462 17301 hierarchical.cpp:1457] Performed allocation for 1 agents in 112158ns
3: I1120 03:37:43.108158 17298 master.cpp:10024] Removing offer 94078a06-852d-40e4-96b9-3c47da182e0b-O2
3: I1120 03:37:43.108265 17298 master.cpp:4228] Processing ACCEPT call for offers: [ 94078a06-852d-40e4-96b9-3c47da182e0b-O2 ] on agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 at slave(883)@172.17.0.2:60428 (a89a9485b29e) for framework 94078a06-852d-40e4-96b9-3c47da182e0b-0001 (creator-framework) at scheduler-4dfb3f47-3719-47ae-957b-737f48a4c053@172.17.0.2:60428
3: I1120 03:37:43.108387 17298 master.cpp:3790] Authorizing principal 'creator-principal' to create volumes '[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"creator-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: I1120 03:37:43.110033 17290 master.cpp:4704] Applying CREATE operation for volumes [{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"creator-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}] from framework 94078a06-852d-40e4-96b9-3c47da182e0b-0001 (creator-framework) at scheduler-4dfb3f47-3719-47ae-957b-737f48a4c053@172.17.0.2:60428 to agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 at slave(883)@172.17.0.2:60428 (a89a9485b29e)
3: I1120 03:37:43.110904 17290 master.cpp:9969] Sending updated checkpointed resources disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk1,id1:path1]:2048 to agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 at slave(883)@172.17.0.2:60428 (a89a9485b29e)
3: I1120 03:37:43.112815 17303 slave.cpp:3587] Updated checkpointed resources from {} to disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk1,id1:path1]:2048
3: I1120 03:37:43.115633 17302 hierarchical.cpp:856] Updated allocation of framework 94078a06-852d-40e4-96b9-3c47da182e0b-0001 on agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 from cpus(allocated: default-role):2; mem(allocated: default-role):2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk2]:2048; ports(allocated: default-role):[31000-32000] to cpus(allocated: default-role):2; mem(allocated: default-role):2048; ports(allocated: default-role):[31000-32000]; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk1,id1:path1]:2048
3: I1120 03:37:43.117558 17302 hierarchical.cpp:1132] Recovered cpus(allocated: default-role):2; mem(allocated: default-role):2048; ports(allocated: default-role):[31000-32000]; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk1,id1:path1]:2048, allocated: {}) on agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 from framework 94078a06-852d-40e4-96b9-3c47da182e0b-0001
3: I1120 03:37:43.120666 17297 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.372419ms
3: I1120 03:37:43.121459 17296 master.cpp:8115] Sending 1 offers to framework 94078a06-852d-40e4-96b9-3c47da182e0b-0001 (creator-framework) at scheduler-4dfb3f47-3719-47ae-957b-737f48a4c053@172.17.0.2:60428
3: I1120 03:37:43.121939 17294 sched.cpp:921] Scheduler::resourceOffers took 95265ns
3: I1120 03:37:43.122587 17301 master.cpp:5432] Processing DECLINE call for offers: [ 94078a06-852d-40e4-96b9-3c47da182e0b-O3 ] for framework 94078a06-852d-40e4-96b9-3c47da182e0b-0001 (creator-framework) at scheduler-4dfb3f47-3719-47ae-957b-737f48a4c053@172.17.0.2:60428
3: I1120 03:37:43.123705 17301 master.cpp:10024] Removing offer 94078a06-852d-40e4-96b9-3c47da182e0b-O3
3: I1120 03:37:43.123870 17301 master.cpp:3471] Processing SUPPRESS call for framework 94078a06-852d-40e4-96b9-3c47da182e0b-0001 (creator-framework) at scheduler-4dfb3f47-3719-47ae-957b-737f48a4c053@172.17.0.2:60428
3: I1120 03:37:43.124487 17291 hierarchical.cpp:1132] Recovered cpus(allocated: default-role):2; mem(allocated: default-role):2048; ports(allocated: default-role):[31000-32000]; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk1,id1:path1]:2048, allocated: {}) on agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 from framework 94078a06-852d-40e4-96b9-3c47da182e0b-0001
3: I1120 03:37:43.124634 17291 hierarchical.cpp:1244] Suppressed offers for roles { default-role } of framework 94078a06-852d-40e4-96b9-3c47da182e0b-0001
3: I1120 03:37:43.124948 17295 master.cpp:5537] Processing REVIVE call for framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000 (default) at scheduler-c36cc707-0b2e-4c20-a5dc-247f129c584d@172.17.0.2:60428
3: I1120 03:37:43.125079 17298 hierarchical.cpp:1279] Revived offers for roles { default-role } of framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000
3: I1120 03:37:43.126489 17298 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.292049ms
3: I1120 03:37:43.127143 17288 master.cpp:8115] Sending 1 offers to framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000 (default) at scheduler-c36cc707-0b2e-4c20-a5dc-247f129c584d@172.17.0.2:60428
3: I1120 03:37:43.127607 17300 sched.cpp:921] Scheduler::resourceOffers took 93214ns
3: I1120 03:37:43.129781 17303 master.cpp:10024] Removing offer 94078a06-852d-40e4-96b9-3c47da182e0b-O4
3: I1120 03:37:43.129928 17303 master.cpp:4228] Processing ACCEPT call for offers: [ 94078a06-852d-40e4-96b9-3c47da182e0b-O4 ] on agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 at slave(883)@172.17.0.2:60428 (a89a9485b29e) for framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000 (default) at scheduler-c36cc707-0b2e-4c20-a5dc-247f129c584d@172.17.0.2:60428
3: I1120 03:37:43.130092 17303 master.cpp:3842] Authorizing principal 'test-principal' to destroy volumes '[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"creator-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: W1120 03:37:43.131295 17303 master.cpp:2363] Dropping DESTROY offer operation from framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000 (default) at scheduler-c36cc707-0b2e-4c20-a5dc-247f129c584d@172.17.0.2:60428: Not authorized to destroy persistent volumes as 'test-principal'
3: I1120 03:37:43.132853 17294 hierarchical.cpp:1132] Recovered cpus(allocated: default-role):2; mem(allocated: default-role):2048; ports(allocated: default-role):[31000-32000]; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk1,id1:path1]:2048, allocated: {}) on agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 from framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000
3: I1120 03:37:43.136036 17301 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.368297ms
3: I1120 03:37:43.136703 17291 master.cpp:8115] Sending 1 offers to framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000 (default) at scheduler-c36cc707-0b2e-4c20-a5dc-247f129c584d@172.17.0.2:60428
3: I1120 03:37:43.137176 17291 sched.cpp:921] Scheduler::resourceOffers took 93259ns
3: I1120 03:37:43.137450 17287 sched.cpp:2009] Asked to stop the driver
3: I1120 03:37:43.137564 17295 sched.cpp:1191] Stopping framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000
3: I1120 03:37:43.137821 17298 master.cpp:8792] Processing TEARDOWN call for framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000 (default) at scheduler-c36cc707-0b2e-4c20-a5dc-247f129c584d@172.17.0.2:60428
3: I1120 03:37:43.137847 17298 master.cpp:8804] Removing framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000 (default) at scheduler-c36cc707-0b2e-4c20-a5dc-247f129c584d@172.17.0.2:60428
3: I1120 03:37:43.137857 17298 master.cpp:3331] Deactivating framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000 (default) at scheduler-c36cc707-0b2e-4c20-a5dc-247f129c584d@172.17.0.2:60428
3: I1120 03:37:43.137923 17287 sched.cpp:2009] Asked to stop the driver
3: I1120 03:37:43.137969 17288 hierarchical.cpp:419] Deactivated framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000
3: I1120 03:37:43.138118 17302 sched.cpp:1191] Stopping framework 94078a06-852d-40e4-96b9-3c47da182e0b-0001
3: I1120 03:37:43.138772 17298 master.cpp:10024] Removing offer 94078a06-852d-40e4-96b9-3c47da182e0b-O5
3: I1120 03:37:43.138986 17301 slave.cpp:3267] Asked to shut down framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000 by master@172.17.0.2:60428
3: I1120 03:37:43.139017 17301 slave.cpp:3282] Cannot shut down unknown framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000
3: I1120 03:37:43.139297 17298 master.cpp:8792] Processing TEARDOWN call for framework 94078a06-852d-40e4-96b9-3c47da182e0b-0001 (creator-framework) at scheduler-4dfb3f47-3719-47ae-957b-737f48a4c053@172.17.0.2:60428
3: I1120 03:37:43.139320 17298 master.cpp:8804] Removing framework 94078a06-852d-40e4-96b9-3c47da182e0b-0001 (creator-framework) at scheduler-4dfb3f47-3719-47ae-957b-737f48a4c053@172.17.0.2:60428
3: I1120 03:37:43.139330 17298 master.cpp:3331] Deactivating framework 94078a06-852d-40e4-96b9-3c47da182e0b-0001 (creator-framework) at scheduler-4dfb3f47-3719-47ae-957b-737f48a4c053@172.17.0.2:60428
3: I1120 03:37:43.139487 17296 slave.cpp:3267] Asked to shut down framework 94078a06-852d-40e4-96b9-3c47da182e0b-0001 by master@172.17.0.2:60428
3: I1120 03:37:43.139524 17296 slave.cpp:3282] Cannot shut down unknown framework 94078a06-852d-40e4-96b9-3c47da182e0b-0001
3: I1120 03:37:43.140061 17289 hierarchical.cpp:1132] Recovered cpus(allocated: default-role):2; mem(allocated: default-role):2048; ports(allocated: default-role):[31000-32000]; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iWZlIT/disk1,id1:path1]:2048, allocated: {}) on agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 from framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000
3: I1120 03:37:43.140306 17289 hierarchical.cpp:358] Removed framework 94078a06-852d-40e4-96b9-3c47da182e0b-0000
3: I1120 03:37:43.140377 17289 hierarchical.cpp:419] Deactivated framework 94078a06-852d-40e4-96b9-3c47da182e0b-0001
3: I1120 03:37:43.140632 17289 hierarchical.cpp:358] Removed framework 94078a06-852d-40e4-96b9-3c47da182e0b-0001
3: I1120 03:37:43.140800 17287 slave.cpp:883] Agent terminating
3: I1120 03:37:43.140990 17301 master.cpp:1309] Agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 at slave(883)@172.17.0.2:60428 (a89a9485b29e) disconnected
3: I1120 03:37:43.141019 17301 master.cpp:3368] Disconnecting agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 at slave(883)@172.17.0.2:60428 (a89a9485b29e)
3: I1120 03:37:43.141098 17301 master.cpp:3387] Deactivating agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 at slave(883)@172.17.0.2:60428 (a89a9485b29e)
3: I1120 03:37:43.141314 17300 hierarchical.cpp:697] Agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0 deactivated
3: I1120 03:37:43.147083 17287 master.cpp:1151] Master terminating
3: I1120 03:37:43.147935 17294 hierarchical.cpp:633] Removed agent 94078a06-852d-40e4-96b9-3c47da182e0b-S0
3: [ OK ] DiskResource/PersistentVolumeTest.BadACLDropCreateAndDestroy/1 (107 ms)
3: [----------] 34 tests from DiskResource/PersistentVolumeTest (11428 ms total)
3:
3: [----------] Global test environment tear-down
3: [==========] 1711 tests from 180 test cases ran. (359051 ms total)
3: [ PASSED ] 1710 tests.
3: [ FAILED ] 1 test, listed below:
3: [ FAILED ] SlaveTest.RegisteredAgentReregisterAfterFailover
3:
3: 1 FAILED TEST
3: YOU HAVE 23 DISABLED TESTS
3:
3: I1120 03:37:43.214067 17304 process.cpp:1052] Failed to accept socket: future discarded
3/3 Test #3: MesosTests .......................***Failed 363.55 sec
67% tests passed, 1 tests failed out of 3
Total Test time (real) = 380.11 sec
The following tests FAILED:
3 - MesosTests (Failed)
Errors while running CTest
make[3]: Leaving directory `/mesos/build'
make[3]: *** [CMakeFiles/check] Error 8
make[2]: *** [CMakeFiles/check.dir/all] Error 2
make[2]: Leaving directory `/mesos/build'
make[1]: *** [CMakeFiles/check.dir/rule] Error 2
make[1]: Leaving directory `/mesos/build'
make: *** [check] Error 2
+ docker rmi mesos-1511146684-13221
Untagged: mesos-1511146684-13221:latest
Deleted: sha256:8361853a6a4ab79d40f69f47ea7dbade10744756d996d8466074eeff51c95323
Deleted: sha256:c3ad48769afa8a5664f806ebf4f7eb2e1e73bae3992a545123ead808a099d31e
Deleted: sha256:bf07a066dab1b1150c8590c538c845ba827b22e4578398c0583ac77e9c6c1d58
Deleted: sha256:af118e6c4b744e1fbe39e7f1ca8204a034e5a5c0ebdd5bf0030e13ff6fbdff1b
Deleted: sha256:0861bf7f201775940f146c24022fb87f3c1430f1e33b7ae7a6bed246eede8bcf
Deleted: sha256:f4ecfc9871ef03f6b9b250d661e52577afdebd9b694c0c32ec193b6d37bb6747
Deleted: sha256:a95c88e2fdde0b225a62f5265502c0e03fd760f7cde669329e56eb61f5a8ba53
Deleted: sha256:bfbef10602b82edb8d9744bbc33da34d13050c06a1ed7e050fd74b26c7beea9f
Deleted: sha256:a3dbb8e6d93ede59ba0b84cb4db5e7057b174947d5b1427f76bce8e97c441e7d
Deleted: sha256:a4fbb6cc3fb5237e0a4cea8244052498c66b044ff4fe5980184aecf12be6be71
Deleted: sha256:749628b4fdab6de6018817e47dfad5a8f58b3ea6c817d80ba2665f297045fab6
Deleted: sha256:5ffd6eae97fbf5b778ad1dee8ca24361a8524ab75abccff940061a99d2654d7b
Deleted: sha256:3f4a0d934e34babbbd99f38b36a063766878163b8c45897d24db245abad52ac3
Deleted: sha256:e14fee3171bc281854cb1fcaedca330dd5f3aa9870fdefe7b99c5b5d495107e3
Deleted: sha256:3e39440fee08f476ed5d61d982f74f573d253e47791d9d7a974abe9e9cad46be
Deleted: sha256:8e36d43ca1da18590d1816b736380d388215bc09def037582821e87c81f06076
Deleted: sha256:3c9c629ba90d8cdc645170242b58498748c224b5bc861fd66addaf41cfdb6fb6
Deleted: sha256:9138d93cf7e1c4ed60ab3bb35b7140b25880d251deb473d2d2ecc7fa39f297e7
Deleted: sha256:72f8b81a2b5b1861de89f30de5e4085c98e37d1f639957b0bf379911a81bfba9
Deleted: sha256:7395c6c73c63eb253ac61e971365dfe466c491c40f4c674cce54a75cc0a06ce0
Deleted: sha256:8fc89068466f861e1f1b55dae17c93b6698c62a715095f4edcce2d825124c367
Deleted: sha256:87e53b8c425904c811f8d7eefc5fa53be6eedf04155192a3c8fa45893a7a9a56
Deleted: sha256:13b3e505ecb9793ebfe976e77c8fa42e316c6cf2730b01de5ec0819a1718f538
Deleted: sha256:d64d1675a93d6d3fe93f2399d0c6972227b9631a3fd621241c0c5aa6c20fb8bf
Deleted: sha256:bdea7b722332c27b109c033bcec24b730e5a5dbd0dc506bd9b5a4408841c8f1b
Deleted: sha256:f62b5a1365c55c454f832624aec2143d7d9490c4afa544813b5b1abd3f8bb66a
Deleted: sha256:60029ba64b0686ca5f1bb05ef7be39dee5cd067ec023f54cc58e05cd17bb6b01
Deleted: sha256:895ab53fb225304f22c88a3547ec18c666fa0c3eb15f815e524820e6cd7d18ef
Deleted: sha256:f88d824f134ef4f0d4e20c29b3af022bc7369cd1ccae36ec3bcb91313a65e0ce
Deleted: sha256:d213f8609cf20c711dbeb65486a91fabea2c78ba1d67ee0614f09d61a3ab6e89
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user benjamin.hindman@gmail.com
Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4474
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4474/display/redirect?page=changes>
Changes:
[benjamin.hindman] Fixed bug where we fail to hold onto PollSocketImpl reference.
[benjamin.hindman] Used loop in SocketImpl.
[benjamin.hindman] Used loop in PollSocketImpl.
[benjamin.hindman] Added a TODO for loop.
[benjamin.hindman] Used inet::Address and inet::Socket explicitly.
[benjamin.hindman] Cleanups inside of synchronized blocks.
[benjamin.hindman] Removed test dependency on internal process::internal::discarded.
[benjamin.hindman] Added Future::onAbandoned and Future::isAbandoned.
[benjamin.hindman] Added Future::recover.
[benjamin.hindman] Added stringification support for Future.
[benjamin.hindman] Added Future::onAbandoned semantics to process::collect/await.
[benjamin.hindman] Used Future::recover in Mesos.
[benjamin.hindman] Added overload of process::await that takes and returns single future.
[benjamin.hindman] Added discard happens-before relationship in process::await/collect.
[benjamin.hindman] Added safe downcasts for Socket.
------------------------------------------
[...truncated 14.65 MB...]
3: type: NONE
3: }
3: }
3: " --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --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/3h3BvS/credentials" --filter_gpu_resources="true" --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" --max_unreachable_tasks_per_framework="1000" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --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="/usr/local/share/mesos/webui" --work_dir="/tmp/3h3BvS/master" --zk_session_timeout="10secs"
3: I1120 02:43:39.425649 17292 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1120 02:43:39.425663 17292 master.cpp:505] Master only allowing authenticated agents to register
3: I1120 02:43:39.425671 17292 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1120 02:43:39.425681 17292 credentials.hpp:37] Loading credentials for authentication from '/tmp/3h3BvS/credentials'
3: I1120 02:43:39.426039 17292 master.cpp:555] Using default 'crammd5' authenticator
3: I1120 02:43:39.426162 17292 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1120 02:43:39.426360 17292 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1120 02:43:39.426534 17292 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1120 02:43:39.426694 17292 master.cpp:634] Authorization enabled
3: I1120 02:43:39.426861 17295 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1120 02:43:39.426897 17301 whitelist_watcher.cpp:77] No whitelist given
3: I1120 02:43:39.429096 17289 master.cpp:2213] Elected as the leading master!
3: I1120 02:43:39.429128 17289 master.cpp:1693] Recovering from registrar
3: I1120 02:43:39.429344 17288 registrar.cpp:347] Recovering registrar
3: I1120 02:43:39.429914 17288 registrar.cpp:391] Successfully fetched the registry (0B) in 529152ns
3: I1120 02:43:39.430011 17288 registrar.cpp:495] Applied 1 operations in 23232ns; attempting to update the registry
3: I1120 02:43:39.430613 17288 registrar.cpp:552] Successfully updated the registry in 550912ns
3: I1120 02:43:39.430747 17288 registrar.cpp:424] Successfully recovered registrar
3: I1120 02:43:39.431257 17288 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1120 02:43:39.431396 17296 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: I1120 02:43:39.433706 17294 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/quota'
3: I1120 02:43:39.434881 17288 http.cpp:1185] HTTP POST for /master/quota from 172.17.0.2:42016
3: I1120 02:43:39.434919 17288 quota_handler.cpp:435] Setting quota from request: '{"force":true,"guarantee":[{"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}],"role":"role1"}'
3: I1120 02:43:39.435448 17288 quota_handler.cpp:745] Authorizing principal 'test-principal-2' to update quota for role 'role1'
3: I1120 02:43:39.439141 17294 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/quota'
3: I1120 02:43:39.440392 17302 http.cpp:1185] HTTP POST for /master/quota from 172.17.0.2:42017
3: I1120 02:43:39.440426 17302 quota_handler.cpp:435] Setting quota from request: '{"force":true,"guarantee":[{"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}],"role":"role1"}'
3: I1120 02:43:39.440925 17302 quota_handler.cpp:745] Authorizing principal 'test-principal' to update quota for role 'role1'
3: I1120 02:43:39.441412 17297 quota_handler.cpp:559] Using force flag to override quota capacity heuristic check
3: I1120 02:43:39.441855 17291 registrar.cpp:495] Applied 1 operations in 43909ns; attempting to update the registry
3: I1120 02:43:39.442380 17291 registrar.cpp:552] Successfully updated the registry in 461056ns
3: I1120 02:43:39.442914 17294 hierarchical.cpp:1317] Set quota [{"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] for role 'role1'
3: I1120 02:43:39.445727 17288 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/quota'
3: I1120 02:43:39.447012 17299 http.cpp:1185] HTTP GET for /master/quota from 172.17.0.2:42018
3: I1120 02:43:39.447046 17299 quota_handler.cpp:360] Handling quota status request
3: I1120 02:43:39.447103 17299 quota_handler.cpp:716] Authorizing principal 'test-principal-2' to get quota for role 'role1'
3: I1120 02:43:39.451213 17296 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/quota'
3: I1120 02:43:39.452527 17292 http.cpp:1185] HTTP GET for /master/quota from 172.17.0.2:42019
3: I1120 02:43:39.452564 17292 quota_handler.cpp:360] Handling quota status request
3: I1120 02:43:39.452616 17292 quota_handler.cpp:716] Authorizing principal 'test-principal' to get quota for role 'role1'
3: I1120 02:43:39.457288 17289 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/quota/role1'
3: I1120 02:43:39.458495 17293 http.cpp:1185] HTTP DELETE for /master/quota/role1 from 172.17.0.2:42020
3: I1120 02:43:39.458536 17293 quota_handler.cpp:620] Removing quota for request path: '/master/quota/role1'
3: I1120 02:43:39.458614 17293 quota_handler.cpp:745] Authorizing principal 'test-principal-2' to update quota for role 'role1'
3: I1120 02:43:39.462357 17298 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/quota/role1'
3: I1120 02:43:39.463831 17299 http.cpp:1185] HTTP DELETE for /master/quota/role1 from 172.17.0.2:42021
3: I1120 02:43:39.463866 17299 quota_handler.cpp:620] Removing quota for request path: '/master/quota/role1'
3: I1120 02:43:39.463961 17299 quota_handler.cpp:745] Authorizing principal 'test-principal' to update quota for role 'role1'
3: I1120 02:43:39.464769 17291 registrar.cpp:495] Applied 1 operations in 49074ns; attempting to update the registry
3: I1120 02:43:39.465345 17300 registrar.cpp:552] Successfully updated the registry in 508160ns
3: I1120 02:43:39.465713 17298 hierarchical.cpp:1339] Removed quota [{"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] for role 'role1'
3: I1120 02:43:39.467032 17294 master.cpp:1151] Master terminating
3: [ OK ] MasterQuotaTest.AuthorizeGetUpdateQuotaRequests (55 ms)
3: [ RUN ] MasterQuotaTest.AuthorizeGetUpdateQuotaRequestsWithoutPrincipal
3: I1120 02:43:39.475177 17286 cluster.cpp:162] Creating default 'local' authorizer
3: I1120 02:43:39.478747 17294 master.cpp:448] Master 7aadf8e9-78d7-4614-89c7-bba79e129200 (4c4dffa9583f) started on 172.17.0.2:38369
3: I1120 02:43:39.478775 17294 master.cpp:450] Flags at startup: --acls="get_quotas {
3: principals {
3: type: ANY
3: }
3: roles {
3: values: "role1"
3: }
3: }
3: update_quotas {
3: principals {
3: type: ANY
3: }
3: roles {
3: type: ANY
3: }
3: }
3: " --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="false" --authenticate_http_readonly="false" --authenticate_http_readwrite="false" --authenticators="crammd5" --authorizers="local" --filter_gpu_resources="true" --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" --max_unreachable_tasks_per_framework="1000" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --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="/usr/local/share/mesos/webui" --work_dir="/tmp/xuNTxs/master" --zk_session_timeout="10secs"
3: I1120 02:43:39.479188 17294 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1120 02:43:39.479203 17294 master.cpp:505] Master only allowing authenticated agents to register
3: I1120 02:43:39.479214 17294 master.cpp:514] Master allowing HTTP frameworks to register without authentication
3: I1120 02:43:39.479238 17294 master.cpp:555] Using default 'crammd5' authenticator
3: W1120 02:43:39.479255 17294 authenticator.cpp:513] No credentials provided, authentication requests will be refused
3: I1120 02:43:39.479367 17294 master.cpp:634] Authorization enabled
3: I1120 02:43:39.479524 17296 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1120 02:43:39.479566 17291 whitelist_watcher.cpp:77] No whitelist given
3: I1120 02:43:39.482550 17288 master.cpp:2213] Elected as the leading master!
3: I1120 02:43:39.482583 17288 master.cpp:1693] Recovering from registrar
3: I1120 02:43:39.482686 17295 registrar.cpp:347] Recovering registrar
3: I1120 02:43:39.483273 17292 registrar.cpp:391] Successfully fetched the registry (0B) in 524032ns
3: I1120 02:43:39.483376 17292 registrar.cpp:495] Applied 1 operations in 25617ns; attempting to update the registry
3: I1120 02:43:39.483954 17292 registrar.cpp:552] Successfully updated the registry in 522240ns
3: I1120 02:43:39.484086 17292 registrar.cpp:424] Successfully recovered registrar
3: I1120 02:43:39.484434 17292 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1120 02:43:39.484509 17289 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: I1120 02:43:39.486717 17290 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/quota'
3: I1120 02:43:39.488051 17298 http.cpp:1185] HTTP POST for /master/quota from 172.17.0.2:42022
3: I1120 02:43:39.488086 17298 quota_handler.cpp:435] Setting quota from request: '{"force":true,"guarantee":[{"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}],"role":"role1"}'
3: I1120 02:43:39.488550 17298 quota_handler.cpp:745] Authorizing principal 'ANY' to update quota for role 'role1'
3: I1120 02:43:39.489019 17292 quota_handler.cpp:559] Using force flag to override quota capacity heuristic check
3: I1120 02:43:39.489444 17293 registrar.cpp:495] Applied 1 operations in 42242ns; attempting to update the registry
3: I1120 02:43:39.489998 17293 registrar.cpp:552] Successfully updated the registry in 494848ns
3: I1120 02:43:39.490752 17288 hierarchical.cpp:1317] Set quota [{"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] for role 'role1'
3: I1120 02:43:39.493405 17293 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/quota'
3: I1120 02:43:39.494709 17288 http.cpp:1185] HTTP GET for /master/quota from 172.17.0.2:42023
3: I1120 02:43:39.494741 17288 quota_handler.cpp:360] Handling quota status request
3: I1120 02:43:39.494786 17288 quota_handler.cpp:716] Authorizing principal 'ANY' to get quota for role 'role1'
3: I1120 02:43:39.499534 17291 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/quota/role1'
3: I1120 02:43:39.500857 17292 http.cpp:1185] HTTP DELETE for /master/quota/role1 from 172.17.0.2:42024
3: I1120 02:43:39.500890 17292 quota_handler.cpp:620] Removing quota for request path: '/master/quota/role1'
3: I1120 02:43:39.500963 17292 quota_handler.cpp:745] Authorizing principal 'ANY' to update quota for role 'role1'
3: I1120 02:43:39.501767 17295 registrar.cpp:495] Applied 1 operations in 48253ns; attempting to update the registry
3: I1120 02:43:39.502336 17295 registrar.cpp:552] Successfully updated the registry in 510976ns
3: I1120 02:43:39.502666 17290 hierarchical.cpp:1339] Removed quota [{"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] for role 'role1'
3: I1120 02:43:39.504118 17286 master.cpp:1151] Master terminating
3: [ OK ] MasterQuotaTest.AuthorizeGetUpdateQuotaRequestsWithoutPrincipal (37 ms)
3: [----------] 16 tests from MasterQuotaTest (1003 ms total)
3:
3: [----------] 79 tests from MasterTest
3: [ RUN ] MasterTest.TaskRunning
3: I1120 02:43:39.510716 17286 cluster.cpp:162] Creating default 'local' authorizer
3: I1120 02:43:39.514240 17292 master.cpp:448] Master a5359b03-bbfc-4bd5-9275-c571ac045fdb (4c4dffa9583f) started on 172.17.0.2:38369
3: I1120 02:43:39.514266 17292 master.cpp:450] 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/rmc8F2/credentials" --filter_gpu_resources="true" --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" --max_unreachable_tasks_per_framework="1000" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --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="/usr/local/share/mesos/webui" --work_dir="/tmp/rmc8F2/master" --zk_session_timeout="10secs"
3: I1120 02:43:39.514642 17292 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1120 02:43:39.514653 17292 master.cpp:505] Master only allowing authenticated agents to register
3: I1120 02:43:39.514658 17292 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1120 02:43:39.514665 17292 credentials.hpp:37] Loading credentials for authentication from '/tmp/rmc8F2/credentials'
3: I1120 02:43:39.514991 17292 master.cpp:555] Using default 'crammd5' authenticator
3: I1120 02:43:39.515161 17292 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1120 02:43:39.515350 17292 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1120 02:43:39.515576 17292 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1120 02:43:39.515729 17292 master.cpp:634] Authorization enabled
3: I1120 02:43:39.515867 17289 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1120 02:43:39.515959 17294 whitelist_watcher.cpp:77] No whitelist given
3: I1120 02:43:39.518756 17293 master.cpp:2213] Elected as the leading master!
3: I1120 02:43:39.518792 17293 master.cpp:1693] Recovering from registrar
3: I1120 02:43:39.519075 17299 registrar.cpp:347] Recovering registrar
3: I1120 02:43:39.519572 17301 registrar.cpp:391] Successfully fetched the registry (0B) in 450816ns
3: I1120 02:43:39.519667 17301 registrar.cpp:495] Applied 1 operations in 24357ns; attempting to update the registry
3: I1120 02:43:39.520251 17301 registrar.cpp:552] Successfully updated the registry in 531968ns
3: I1120 02:43:39.520376 17301 registrar.cpp:424] Successfully recovered registrar
3: I1120 02:43:39.520745 17289 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1120 02:43:39.520805 17295 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: W1120 02:43:39.526341 17286 process.cpp:3185] Attempted to spawn already running process files@172.17.0.2:38369
3: I1120 02:43:39.526695 17286 cluster.cpp:448] Creating default 'local' authorizer
3: I1120 02:43:39.529165 17301 slave.cpp:262] Mesos agent started on (332)@172.17.0.2:38369
3: I1120 02:43:39.529191 17301 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/MasterTest_TaskRunning_Fi2E1c/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/MasterTest_TaskRunning_Fi2E1c/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/MasterTest_TaskRunning_Fi2E1c/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/MasterTest_TaskRunning_Fi2E1c/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/MasterTest_TaskRunning_Fi2E1c/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/MasterTest_TaskRunning_Fi2E1c" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/MasterTest_TaskRunning_l3XSQC" --zk_session_timeout="10secs"
3: I1120 02:43:39.529626 17301 credentials.hpp:86] Loading credential for authentication from '/tmp/MasterTest_TaskRunning_Fi2E1c/credential'
3: W1120 02:43:39.529728 17286 process.cpp:3185] Attempted to spawn already running process version@172.17.0.2:38369
3: I1120 02:43:39.529801 17301 slave.cpp:295] Agent using credential for: test-principal
3: I1120 02:43:39.529819 17301 credentials.hpp:37] Loading credentials for authentication from '/tmp/MasterTest_TaskRunning_Fi2E1c/http_credentials'
3: I1120 02:43:39.530084 17301 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1120 02:43:39.530243 17301 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1120 02:43:39.530870 17286 sched.cpp:232] Version: 1.5.0
3: I1120 02:43:39.531559 17290 sched.cpp:336] New master detected at master@172.17.0.2:38369
3: I1120 02:43:39.531677 17290 sched.cpp:396] Authenticating with master master@172.17.0.2:38369
3: I1120 02:43:39.531704 17290 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1120 02:43:39.532059 17293 authenticatee.cpp:121] Creating new client SASL connection
3: I1120 02:43:39.532033 17301 slave.cpp:593] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1120 02:43:39.532318 17301 slave.cpp:601] Agent attributes: [ ]
3: I1120 02:43:39.532330 17301 slave.cpp:610] Agent hostname: 4c4dffa9583f
3: I1120 02:43:39.532425 17302 master.cpp:8285] Authenticating scheduler-17b2bf41-25e4-4059-a3e6-e80a827f82ef@172.17.0.2:38369
3: I1120 02:43:39.532569 17299 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(696)@172.17.0.2:38369
3: I1120 02:43:39.532595 17295 status_update_manager.cpp:177] Pausing sending status updates
3: I1120 02:43:39.532840 17297 authenticator.cpp:98] Creating new server SASL connection
3: I1120 02:43:39.533134 17287 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1120 02:43:39.533161 17287 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1120 02:43:39.533311 17287 authenticator.cpp:204] Received SASL authentication start
3: I1120 02:43:39.533382 17287 authenticator.cpp:326] Authentication requires more steps
3: I1120 02:43:39.533531 17298 authenticatee.cpp:259] Received SASL authentication step
3: I1120 02:43:39.533679 17298 authenticator.cpp:232] Received SASL authentication step
3: I1120 02:43:39.533709 17298 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '4c4dffa9583f' server FQDN: '4c4dffa9583f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1120 02:43:39.533723 17298 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1120 02:43:39.533757 17298 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1120 02:43:39.533779 17298 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '4c4dffa9583f' server FQDN: '4c4dffa9583f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1120 02:43:39.533795 17298 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1120 02:43:39.533807 17298 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1120 02:43:39.533830 17298 authenticator.cpp:318] Authentication success
3: I1120 02:43:39.533957 17289 authenticatee.cpp:299] Authentication success
3: I1120 02:43:39.534027 17290 master.cpp:8315] Successfully authenticated principal 'test-principal' at scheduler-17b2bf41-25e4-4059-a3e6-e80a827f82ef@172.17.0.2:38369
3: I1120 02:43:39.534086 17298 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(696)@172.17.0.2:38369
3: I1120 02:43:39.534240 17295 state.cpp:64] Recovering state from '/tmp/MasterTest_TaskRunning_l3XSQC/meta'
3: I1120 02:43:39.534415 17289 sched.cpp:502] Successfully authenticated with master master@172.17.0.2:38369
3: I1120 02:43:39.534443 17289 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.2:38369
3: I1120 02:43:39.534554 17295 status_update_manager.cpp:203] Recovering status update manager
3: I1120 02:43:39.534586 17289 sched.cpp:857] Will retry registration in 702.679884ms if necessary
3: I1120 02:43:39.534909 17291 master.cpp:2961] Received SUBSCRIBE call for framework 'default' at scheduler-17b2bf41-25e4-4059-a3e6-e80a827f82ef@172.17.0.2:38369
3: I1120 02:43:39.534996 17291 master.cpp:2278] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
3: I1120 02:43:39.535068 17293 slave.cpp:6441] Finished recovery
3: I1120 02:43:39.535498 17291 master.cpp:3041] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1120 02:43:39.535909 17288 status_update_manager.cpp:177] Pausing sending status updates
3: I1120 02:43:39.535974 17299 slave.cpp:1007] New master detected at master@172.17.0.2:38369
3: I1120 02:43:39.536093 17299 slave.cpp:1042] Detecting new master
3: I1120 02:43:39.536141 17287 sched.cpp:751] Framework registered with a5359b03-bbfc-4bd5-9275-c571ac045fdb-0000
3: I1120 02:43:39.536182 17287 sched.cpp:765] Scheduler::registered took 22669ns
3: I1120 02:43:39.536381 17298 hierarchical.cpp:306] Added framework a5359b03-bbfc-4bd5-9275-c571ac045fdb-0000
3: I1120 02:43:39.536592 17298 hierarchical.cpp:1457] Performed allocation for 0 agents in 76801ns
3: I1120 02:43:39.545500 17296 slave.cpp:1069] Authenticating with master master@172.17.0.2:38369
3: I1120 02:43:39.545578 17296 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1120 02:43:39.545792 17300 authenticatee.cpp:121] Creating new client SASL connection
3: I1120 02:43:39.546090 17302 master.cpp:8285] Authenticating slave(332)@172.17.0.2:38369
3: I1120 02:43:39.546236 17290 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(697)@172.17.0.2:38369
3: I1120 02:43:39.546545 17293 authenticator.cpp:98] Creating new server SASL connection
3: I1120 02:43:39.546777 17297 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1120 02:43:39.546799 17297 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1120 02:43:39.546913 17297 authenticator.cpp:204] Received SASL authentication start
3: I1120 02:43:39.546967 17297 authenticator.cpp:326] Authentication requires more steps
3: I1120 02:43:39.547096 17288 authenticatee.cpp:259] Received SASL authentication step
3: I1120 02:43:39.547262 17291 authenticator.cpp:232] Received SASL authentication step
3: I1120 02:43:39.547296 17291 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '4c4dffa9583f' server FQDN: '4c4dffa9583f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1120 02:43:39.547305 17291 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1120 02:43:39.547333 17291 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1120 02:43:39.547365 17291 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '4c4dffa9583f' server FQDN: '4c4dffa9583f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1120 02:43:39.547402 17291 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1120 02:43:39.547415 17291 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1120 02:43:39.547431 17291 authenticator.cpp:318] Authentication success
3: I1120 02:43:39.547541 17294 authenticatee.cpp:299] Authentication success
3: I1120 02:43:39.547574 17287 master.cpp:8315] Successfully authenticated principal 'test-principal' at slave(332)@172.17.0.2:38369
3: I1120 02:43:39.547693 17291 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(697)@172.17.0.2:38369
3: I1120 02:43:39.547933 17292 slave.cpp:1161] Successfully authenticated with master master@172.17.0.2:38369
3: I1120 02:43:39.548168 17292 slave.cpp:1682] Will retry registration in 12.165558ms if necessary
3: I1120 02:43:39.548446 17296 master.cpp:6032] Received register agent message from slave(332)@172.17.0.2:38369 (4c4dffa9583f)
3: I1120 02:43:39.548581 17296 master.cpp:3870] Authorizing agent with principal 'test-principal'
3: I1120 02:43:39.548964 17300 master.cpp:6092] Authorized registration of agent at slave(332)@172.17.0.2:38369 (4c4dffa9583f)
3: I1120 02:43:39.549072 17300 master.cpp:6185] Registering agent at slave(332)@172.17.0.2:38369 (4c4dffa9583f) with id a5359b03-bbfc-4bd5-9275-c571ac045fdb-S0
3: I1120 02:43:39.549448 17290 registrar.cpp:495] Applied 1 operations in 57310ns; attempting to update the registry
3: I1120 02:43:39.549952 17294 registrar.cpp:552] Successfully updated the registry in 449024ns
3: I1120 02:43:39.550166 17287 master.cpp:6232] Admitted agent a5359b03-bbfc-4bd5-9275-c571ac045fdb-S0 at slave(332)@172.17.0.2:38369 (4c4dffa9583f)
3: I1120 02:43:39.550890 17295 slave.cpp:1207] Registered with master master@172.17.0.2:38369; given agent ID a5359b03-bbfc-4bd5-9275-c571ac045fdb-S0
3: I1120 02:43:39.551010 17291 status_update_manager.cpp:184] Resuming sending status updates
3: I1120 02:43:39.550787 17287 master.cpp:6263] Registered agent a5359b03-bbfc-4bd5-9275-c571ac045fdb-S0 at slave(332)@172.17.0.2:38369 (4c4dffa9583f) with [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1120 02:43:39.551203 17298 hierarchical.cpp:600] Added agent a5359b03-bbfc-4bd5-9275-c571ac045fdb-S0 (4c4dffa9583f) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
3: I1120 02:43:39.551240 17295 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/MasterTest_TaskRunning_l3XSQC/meta/slaves/a5359b03-bbfc-4bd5-9275-c571ac045fdb-S0/slave.info'
3: I1120 02:43:39.551684 17295 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: I1120 02:43:39.551959 17292 master.cpp:7064] Received update of agent a5359b03-bbfc-4bd5-9275-c571ac045fdb-S0 at slave(332)@172.17.0.2:38369 (4c4dffa9583f) with total oversubscribed resources {}
3: I1120 02:43:39.552211 17292 master.cpp:7082] Ignoring update on agent a5359b03-bbfc-4bd5-9275-c571ac045fdb-S0 at slave(332)@172.17.0.2:38369 (4c4dffa9583f) as it reports no changes
3: I1120 02:43:39.552814 17298 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.441579ms
3: I1120 02:43:39.553541 17296 master.cpp:8115] Sending 1 offers to framework a5359b03-bbfc-4bd5-9275-c571ac045fdb-0000 (default) at scheduler-17b2bf41-25e4-4059-a3e6-e80a827f82ef@172.17.0.2:38369
3: I1120 02:43:39.554191 17302 sched.cpp:921] Scheduler::resourceOffers took 124335ns
3: I1120 02:43:39.556711 17299 master.cpp:10024] Removing offer a5359b03-bbfc-4bd5-9275-c571ac045fdb-O0
3: I1120 02:43:39.556888 17299 master.cpp:4228] Processing ACCEPT call for offers: [ a5359b03-bbfc-4bd5-9275-c571ac045fdb-O0 ] on agent a5359b03-bbfc-4bd5-9275-c571ac045fdb-S0 at slave(332)@172.17.0.2:38369 (4c4dffa9583f) for framework a5359b03-bbfc-4bd5-9275-c571ac045fdb-0000 (default) at scheduler-17b2bf41-25e4-4059-a3e6-e80a827f82ef@172.17.0.2:38369
3: I1120 02:43:39.557003 17299 master.cpp:3597] Authorizing framework principal 'test-principal' to launch task 1
3: W1120 02:43:39.559089 17295 validation.cpp:1391] Executor 'default' for task '1' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
3: W1120 02:43:39.559123 17295 validation.cpp:1403] Executor 'default' for task '1' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
3: I1120 02:43:39.559823 17295 master.cpp:10770] Adding task 1 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] on agent a5359b03-bbfc-4bd5-9275-c571ac045fdb-S0 at slave(332)@172.17.0.2:38369 (4c4dffa9583f)
3: I1120 02:43:39.560691 17295 master.cpp:4976] Launching task 1 of framework a5359b03-bbfc-4bd5-9275-c571ac045fdb-0000 (default) at scheduler-17b2bf41-25e4-4059-a3e6-e80a827f82ef@172.17.0.2:38369 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] on agent a5359b03-bbfc-4bd5-9275-c571ac045fdb-S0 at slave(332)@172.17.0.2:38369 (4c4dffa9583f)
3: I1120 02:43:39.561544 17298 slave.cpp:1803] Got assigned task '1' for framework a5359b03-bbfc-4bd5-9275-c571ac045fdb-0000
Process leaked file descriptors. See https://jenkins.io/redirect/troubleshooting/process-leaked-file-descriptors for more information
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user benjamin.hindman@gmail.com