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/25 20:53:34 UTC

Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4498

See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4498/display/redirect?page=changes>

Changes:

[benjamin.hindman] Improved libprocess documentation.

------------------------------------------
[...truncated 33.46 MB...]
3: I1125 20:53:26.684025 29067 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.2:46464
3: I1125 20:53:26.684200 29067 sched.cpp:857] Will retry registration in 1.680486075secs if necessary
3: I1125 20:53:26.684499 29076 master.cpp:2963] Received SUBSCRIBE call for framework 'no-principal' at scheduler-2ad4f923-12b6-4501-a71d-949512ef6956@172.17.0.2:46464
3: I1125 20:53:26.684613 29076 master.cpp:2280] Authorizing framework principal '' to receive offers for roles '{ default-role }'
3: I1125 20:53:26.685246 29065 master.cpp:3043] Subscribing framework no-principal with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1125 20:53:26.685820 29074 sched.cpp:751] Framework registered with 1e860079-e118-403d-822e-87d627258735-0000
3: I1125 20:53:26.685910 29074 sched.cpp:765] Scheduler::registered took 51743ns
3: I1125 20:53:26.686000 29054 hierarchical.cpp:306] Added framework 1e860079-e118-403d-822e-87d627258735-0000
3: I1125 20:53:26.687631 29054 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.518448ms
3: I1125 20:53:26.688374 29057 master.cpp:8142] Sending 1 offers to framework 1e860079-e118-403d-822e-87d627258735-0000 (no-principal) at scheduler-2ad4f923-12b6-4501-a71d-949512ef6956@172.17.0.2:46464
3: I1125 20:53:26.688928 29068 sched.cpp:921] Scheduler::resourceOffers took 105484ns
3: I1125 20:53:26.689669 29073 hierarchical.cpp:1457] Performed allocation for 1 agents in 124491ns
3: I1125 20:53:26.691854 29072 master.cpp:10063] Removing offer 1e860079-e118-403d-822e-87d627258735-O0
3: I1125 20:53:26.691977 29072 master.cpp:4230] Processing ACCEPT call for offers: [ 1e860079-e118-403d-822e-87d627258735-O0 ] on agent 1e860079-e118-403d-822e-87d627258735-S0 at slave(899)@172.17.0.2:46464 (0ec1a6f6aad0) for framework 1e860079-e118-403d-822e-87d627258735-0000 (no-principal) at scheduler-2ad4f923-12b6-4501-a71d-949512ef6956@172.17.0.2:46464
3: I1125 20:53:26.692097 29072 master.cpp:3792] Authorizing principal 'ANY' to create volumes '[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: I1125 20:53:26.693750 29059 master.cpp:4706] Applying CREATE operation for volumes [{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu\/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 1e860079-e118-403d-822e-87d627258735-0000 (no-principal) at scheduler-2ad4f923-12b6-4501-a71d-949512ef6956@172.17.0.2:46464 to agent 1e860079-e118-403d-822e-87d627258735-S0 at slave(899)@172.17.0.2:46464 (0ec1a6f6aad0)
3: I1125 20:53:26.694646 29059 master.cpp:9945] Sending offer operation '' (uuid: fd692257-9558-464f-a8b4-a7aca5d90a97) to agent 1e860079-e118-403d-822e-87d627258735-S0 at slave(899)@172.17.0.2:46464 (0ec1a6f6aad0)
3: I1125 20:53:26.696552 29069 slave.cpp:3594] Updated checkpointed resources from {} to disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu/disk1,id1:path1]:2048
3: I1125 20:53:26.696650 29069 slave.cpp:6989] Updating the state of offer operation '' (uuid: fd692257-9558-464f-a8b4-a7aca5d90a97) of framework 1e860079-e118-403d-822e-87d627258735-0000 (latest state: OFFER_OPERATION_FINISHED, status update state: OFFER_OPERATION_FINISHED)
3: I1125 20:53:26.696947 29063 master.cpp:9731] Updating the state of offer operation '' (uuid: fd692257-9558-464f-a8b4-a7aca5d90a97) of framework 1e860079-e118-403d-822e-87d627258735-0000 (latest state: OFFER_OPERATION_FINISHED, status update state: OFFER_OPERATION_FINISHED)
3: I1125 20:53:26.701176 29062 hierarchical.cpp:856] Updated allocation of framework 1e860079-e118-403d-822e-87d627258735-0000 on agent 1e860079-e118-403d-822e-87d627258735-S0 from cpus(allocated: default-role):2; mem(allocated: default-role):2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu/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_GoodACLNoPrincipal_3_YD5qvu/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu/disk1,id1:path1]:2048
3: I1125 20:53:26.702821 29062 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_GoodACLNoPrincipal_3_YD5qvu/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu/disk1,id1:path1]:2048, allocated: {}) on agent 1e860079-e118-403d-822e-87d627258735-S0 from framework 1e860079-e118-403d-822e-87d627258735-0000
3: I1125 20:53:26.706853 29077 hierarchical.cpp:1457] Performed allocation for 1 agents in 3.064396ms
3: I1125 20:53:26.707545 29065 master.cpp:8142] Sending 1 offers to framework 1e860079-e118-403d-822e-87d627258735-0000 (no-principal) at scheduler-2ad4f923-12b6-4501-a71d-949512ef6956@172.17.0.2:46464
3: I1125 20:53:26.708137 29071 sched.cpp:921] Scheduler::resourceOffers took 111295ns
3: I1125 20:53:26.710381 29066 master.cpp:10063] Removing offer 1e860079-e118-403d-822e-87d627258735-O1
3: I1125 20:53:26.710495 29066 master.cpp:4230] Processing ACCEPT call for offers: [ 1e860079-e118-403d-822e-87d627258735-O1 ] on agent 1e860079-e118-403d-822e-87d627258735-S0 at slave(899)@172.17.0.2:46464 (0ec1a6f6aad0) for framework 1e860079-e118-403d-822e-87d627258735-0000 (no-principal) at scheduler-2ad4f923-12b6-4501-a71d-949512ef6956@172.17.0.2:46464
3: I1125 20:53:26.710604 29066 master.cpp:3844] Authorizing principal 'ANY' to destroy volumes '[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: I1125 20:53:26.712119 29073 master.cpp:4799] Applying DESTROY operation for volumes [{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu\/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 1e860079-e118-403d-822e-87d627258735-0000 (no-principal) at scheduler-2ad4f923-12b6-4501-a71d-949512ef6956@172.17.0.2:46464 to agent 1e860079-e118-403d-822e-87d627258735-S0 at slave(899)@172.17.0.2:46464 (0ec1a6f6aad0)
3: I1125 20:53:26.712883 29073 master.cpp:9945] Sending offer operation '' (uuid: ed5ba85c-6424-4be4-a39d-7719dfbb3525) to agent 1e860079-e118-403d-822e-87d627258735-S0 at slave(899)@172.17.0.2:46464 (0ec1a6f6aad0)
3: I1125 20:53:26.714323 29056 slave.cpp:3666] Deleting persistent volume 'id1' at '/tmp/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu/disk1/volumes/roles/default-role/id1'
3: I1125 20:53:26.714560 29056 slave.cpp:3594] Updated checkpointed resources from disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu/disk1,id1:path1]:2048 to {}
3: I1125 20:53:26.714643 29056 slave.cpp:6989] Updating the state of offer operation '' (uuid: ed5ba85c-6424-4be4-a39d-7719dfbb3525) of framework 1e860079-e118-403d-822e-87d627258735-0000 (latest state: OFFER_OPERATION_FINISHED, status update state: OFFER_OPERATION_FINISHED)
3: I1125 20:53:26.714844 29056 master.cpp:9731] Updating the state of offer operation '' (uuid: ed5ba85c-6424-4be4-a39d-7719dfbb3525) of framework 1e860079-e118-403d-822e-87d627258735-0000 (latest state: OFFER_OPERATION_FINISHED, status update state: OFFER_OPERATION_FINISHED)
3: I1125 20:53:26.717057 29060 hierarchical.cpp:856] Updated allocation of framework 1e860079-e118-403d-822e-87d627258735-0000 on agent 1e860079-e118-403d-822e-87d627258735-S0 from 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_GoodACLNoPrincipal_3_YD5qvu/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu/disk1,id1:path1]:2048 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_GoodACLNoPrincipal_3_YD5qvu/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu/disk1]:2048
3: I1125 20:53:26.718477 29060 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_GoodACLNoPrincipal_3_YD5qvu/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu/disk1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu/disk1]:2048, allocated: {}) on agent 1e860079-e118-403d-822e-87d627258735-S0 from framework 1e860079-e118-403d-822e-87d627258735-0000
3: I1125 20:53:26.720438 29058 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.390807ms
3: I1125 20:53:26.721089 29061 master.cpp:8142] Sending 1 offers to framework 1e860079-e118-403d-822e-87d627258735-0000 (no-principal) at scheduler-2ad4f923-12b6-4501-a71d-949512ef6956@172.17.0.2:46464
3: I1125 20:53:26.721599 29059 sched.cpp:921] Scheduler::resourceOffers took 95045ns
3: I1125 20:53:26.721907 20035 sched.cpp:2009] Asked to stop the driver
3: I1125 20:53:26.722064 29069 sched.cpp:1191] Stopping framework 1e860079-e118-403d-822e-87d627258735-0000
3: I1125 20:53:26.722316 29063 master.cpp:8819] Processing TEARDOWN call for framework 1e860079-e118-403d-822e-87d627258735-0000 (no-principal) at scheduler-2ad4f923-12b6-4501-a71d-949512ef6956@172.17.0.2:46464
3: I1125 20:53:26.722344 29063 master.cpp:8831] Removing framework 1e860079-e118-403d-822e-87d627258735-0000 (no-principal) at scheduler-2ad4f923-12b6-4501-a71d-949512ef6956@172.17.0.2:46464
3: I1125 20:53:26.722355 29063 master.cpp:3333] Deactivating framework 1e860079-e118-403d-822e-87d627258735-0000 (no-principal) at scheduler-2ad4f923-12b6-4501-a71d-949512ef6956@172.17.0.2:46464
3: I1125 20:53:26.722446 29075 hierarchical.cpp:419] Deactivated framework 1e860079-e118-403d-822e-87d627258735-0000
3: I1125 20:53:26.723145 29063 master.cpp:10063] Removing offer 1e860079-e118-403d-822e-87d627258735-O2
3: I1125 20:53:26.723362 29073 slave.cpp:3270] Asked to shut down framework 1e860079-e118-403d-822e-87d627258735-0000 by master@172.17.0.2:46464
3: I1125 20:53:26.723392 29073 slave.cpp:3285] Cannot shut down unknown framework 1e860079-e118-403d-822e-87d627258735-0000
3: I1125 20:53:26.724033 29065 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_GoodACLNoPrincipal_3_YD5qvu/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu/disk1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_GoodACLNoPrincipal_3_YD5qvu/disk1]:2048, allocated: {}) on agent 1e860079-e118-403d-822e-87d627258735-S0 from framework 1e860079-e118-403d-822e-87d627258735-0000
3: I1125 20:53:26.724367 29065 hierarchical.cpp:358] Removed framework 1e860079-e118-403d-822e-87d627258735-0000
3: I1125 20:53:26.724601 20035 slave.cpp:883] Agent terminating
3: I1125 20:53:26.724802 29066 master.cpp:1311] Agent 1e860079-e118-403d-822e-87d627258735-S0 at slave(899)@172.17.0.2:46464 (0ec1a6f6aad0) disconnected
3: I1125 20:53:26.724830 29066 master.cpp:3370] Disconnecting agent 1e860079-e118-403d-822e-87d627258735-S0 at slave(899)@172.17.0.2:46464 (0ec1a6f6aad0)
3: I1125 20:53:26.724884 29066 master.cpp:3389] Deactivating agent 1e860079-e118-403d-822e-87d627258735-S0 at slave(899)@172.17.0.2:46464 (0ec1a6f6aad0)
3: I1125 20:53:26.725060 29055 hierarchical.cpp:697] Agent 1e860079-e118-403d-822e-87d627258735-S0 deactivated
3: I1125 20:53:26.730892 20035 master.cpp:1153] Master terminating
3: I1125 20:53:26.731796 29075 hierarchical.cpp:633] Removed agent 1e860079-e118-403d-822e-87d627258735-S0
3: [       OK ] DiskResource/PersistentVolumeTest.GoodACLNoPrincipal/3 (102 ms)
3: [ RUN      ] DiskResource/PersistentVolumeTest.BadACLNoPrincipal/0
3: I1125 20:53:26.738255 20035 cluster.cpp:162] Creating default 'local' authorizer
3: I1125 20:53:26.741194 29066 master.cpp:448] Master 86bca794-82bf-4445-9ea6-a9ff72ead453 (0ec1a6f6aad0) started on 172.17.0.2:46464
3: I1125 20:53:26.741211 29066 master.cpp:450] Flags at startup: --acls="create_volumes {
3:   principals {
3:     values: "test-principal"
3:   }
3:   roles {
3:     type: ANY
3:   }
3: }
3: create_volumes {
3:   principals {
3:     type: ANY
3:   }
3:   roles {
3:     type: NONE
3:   }
3: }
3: destroy_volumes {
3:   principals {
3:     type: ANY
3:   }
3:   creator_principals {
3:     type: NONE
3:   }
3: }
3: " --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="false" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/9ur32M/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" --roles="default-role" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/9ur32M/master" --zk_session_timeout="10secs"
3: I1125 20:53:26.741569 29066 master.cpp:501] Master allowing unauthenticated frameworks to register
3: I1125 20:53:26.741575 29066 master.cpp:505] Master only allowing authenticated agents to register
3: I1125 20:53:26.741580 29066 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1125 20:53:26.741585 29066 credentials.hpp:37] Loading credentials for authentication from '/tmp/9ur32M/credentials'
3: I1125 20:53:26.741842 29066 master.cpp:555] Using default 'crammd5' authenticator
3: I1125 20:53:26.741991 29066 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1125 20:53:26.742148 29066 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1125 20:53:26.742278 29066 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1125 20:53:26.742410 29066 master.cpp:634] Authorization enabled
3: W1125 20:53:26.742424 29066 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: I1125 20:53:26.742607 29059 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1125 20:53:26.742626 29067 whitelist_watcher.cpp:77] No whitelist given
3: I1125 20:53:26.745407 29054 master.cpp:2215] Elected as the leading master!
3: I1125 20:53:26.745435 29054 master.cpp:1695] Recovering from registrar
3: I1125 20:53:26.745575 29065 registrar.cpp:347] Recovering registrar
3: I1125 20:53:26.746151 29065 registrar.cpp:391] Successfully fetched the registry (0B) in 0ns
3: I1125 20:53:26.746243 29065 registrar.cpp:495] Applied 1 operations in 25833ns; attempting to update the registry
3: I1125 20:53:26.746937 29065 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1125 20:53:26.747084 29065 registrar.cpp:424] Successfully recovered registrar
3: I1125 20:53:26.747500 29073 master.cpp:1808] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1125 20:53:26.747567 29060 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: W1125 20:53:26.752501 20035 process.cpp:2756] Attempted to spawn already running process files@172.17.0.2:46464
3: I1125 20:53:26.753417 20035 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1125 20:53:26.753913 20035 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1125 20:53:26.754029 20035 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1125 20:53:26.754058 20035 provisioner.cpp:259] Using default backend 'copy'
3: I1125 20:53:26.755861 20035 cluster.cpp:448] Creating default 'local' authorizer
3: I1125 20:53:26.758096 29073 slave.cpp:262] Mesos agent started on (900)@172.17.0.2:46464
3: I1125 20:53:26.758118 29073 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLNoPrincipal_0_u85pzM/store/appc" --authenticate_http_executors="true" --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_BadACLNoPrincipal_0_u85pzM/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_BadACLNoPrincipal_0_u85pzM/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_secret_key="/tmp/DiskResource_PersistentVolumeTest_BadACLNoPrincipal_0_u85pzM/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLNoPrincipal_0_u85pzM/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_BadACLNoPrincipal_0_u85pzM/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"},{"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":4096.0},"type":"SCALAR"}]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLNoPrincipal_0_u85pzM" --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_BadACLNoPrincipal_0_PpHh3r" --zk_session_timeout="10secs"
3: I1125 20:53:26.758615 29073 credentials.hpp:86] Loading credential for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLNoPrincipal_0_u85pzM/credential'
3: I1125 20:53:26.758829 29073 slave.cpp:295] Agent using credential for: test-principal
3: I1125 20:53:26.758846 29073 credentials.hpp:37] Loading credentials for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLNoPrincipal_0_u85pzM/http_credentials'
3: I1125 20:53:26.759146 29073 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1125 20:53:26.759351 29073 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1125 20:53:26.759603 29073 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1125 20:53:26.759707 29073 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1125 20:53:26.759907 29073 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1125 20:53:26.760010 29073 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1125 20:53:26.762235 29073 slave.cpp:593] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":2048.0},"type":"SCALAR"},{"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":4096.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1125 20:53:26.762512 29073 slave.cpp:601] Agent attributes: [  ]
3: I1125 20:53:26.762524 29073 slave.cpp:610] Agent hostname: 0ec1a6f6aad0
3: I1125 20:53:26.762715 29072 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1125 20:53:26.764580 29075 state.cpp:64] Recovering state from '/tmp/DiskResource_PersistentVolumeTest_BadACLNoPrincipal_0_PpHh3r/meta'
3: I1125 20:53:26.764906 29055 task_status_update_manager.cpp:207] Recovering task status update manager
3: I1125 20:53:26.765173 29069 containerizer.cpp:668] Recovering containerizer
3: I1125 20:53:26.766746 29074 provisioner.cpp:455] Provisioner recovery complete
3: I1125 20:53:26.767117 29072 slave.cpp:6493] Finished recovery
3: I1125 20:53:26.767870 29070 slave.cpp:1007] New master detected at master@172.17.0.2:46464
3: I1125 20:53:26.767889 29073 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1125 20:53:26.767956 29070 slave.cpp:1042] Detecting new master
3: I1125 20:53:26.768132 29070 slave.cpp:1069] Authenticating with master master@172.17.0.2:46464
3: I1125 20:53:26.768220 29070 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1125 20:53:26.768466 29065 authenticatee.cpp:121] Creating new client SASL connection
3: I1125 20:53:26.768810 29060 master.cpp:8312] Authenticating slave(900)@172.17.0.2:46464
3: I1125 20:53:26.768930 29055 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1618)@172.17.0.2:46464
3: I1125 20:53:26.769253 29061 authenticator.cpp:98] Creating new server SASL connection
3: I1125 20:53:26.769516 29076 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1125 20:53:26.769544 29076 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1125 20:53:26.769657 29076 authenticator.cpp:204] Received SASL authentication start
3: I1125 20:53:26.769716 29076 authenticator.cpp:326] Authentication requires more steps
3: I1125 20:53:26.769814 29076 authenticatee.cpp:259] Received SASL authentication step
3: I1125 20:53:26.769917 29076 authenticator.cpp:232] Received SASL authentication step
3: I1125 20:53:26.769942 29076 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '0ec1a6f6aad0' server FQDN: '0ec1a6f6aad0' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1125 20:53:26.769950 29076 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1125 20:53:26.769989 29076 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1125 20:53:26.770005 29076 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '0ec1a6f6aad0' server FQDN: '0ec1a6f6aad0' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1125 20:53:26.770012 29076 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1125 20:53:26.770017 29076 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1125 20:53:26.770030 29076 authenticator.cpp:318] Authentication success
3: I1125 20:53:26.770123 29059 authenticatee.cpp:299] Authentication success
3: I1125 20:53:26.770234 29068 master.cpp:8342] Successfully authenticated principal 'test-principal' at slave(900)@172.17.0.2:46464
3: I1125 20:53:26.770257 29059 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1618)@172.17.0.2:46464
3: I1125 20:53:26.770450 29071 slave.cpp:1161] Successfully authenticated with master master@172.17.0.2:46464
3: I1125 20:53:26.770699 29071 slave.cpp:1685] Will retry registration in 12.501011ms if necessary
3: I1125 20:53:26.770922 29074 master.cpp:6036] Received register agent message from slave(900)@172.17.0.2:46464 (0ec1a6f6aad0)
3: I1125 20:53:26.771059 29074 master.cpp:3872] Authorizing agent with principal 'test-principal'
3: I1125 20:53:26.771548 29072 master.cpp:6098] Authorized registration of agent at slave(900)@172.17.0.2:46464 (0ec1a6f6aad0)
3: I1125 20:53:26.771652 29072 master.cpp:6191] Registering agent at slave(900)@172.17.0.2:46464 (0ec1a6f6aad0) with id 86bca794-82bf-4445-9ea6-a9ff72ead453-S0
3: I1125 20:53:26.772055 29063 registrar.cpp:495] Applied 1 operations in 54085ns; attempting to update the registry
3: I1125 20:53:26.772796 29063 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1125 20:53:26.773053 29065 master.cpp:6240] Admitted agent 86bca794-82bf-4445-9ea6-a9ff72ead453-S0 at slave(900)@172.17.0.2:46464 (0ec1a6f6aad0)
3: I1125 20:53:26.773866 29055 slave.cpp:1207] Registered with master master@172.17.0.2:46464; given agent ID 86bca794-82bf-4445-9ea6-a9ff72ead453-S0
3: I1125 20:53:26.773854 29065 master.cpp:6276] Registered agent 86bca794-82bf-4445-9ea6-a9ff72ead453-S0 at slave(900)@172.17.0.2:46464 (0ec1a6f6aad0) with cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)]):4096; ports:[31000-32000]
3: I1125 20:53:26.773974 29077 task_status_update_manager.cpp:188] Resuming sending task status updates
3: I1125 20:53:26.774163 29061 hierarchical.cpp:600] Added agent 86bca794-82bf-4445-9ea6-a9ff72ead453-S0 (0ec1a6f6aad0) with cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)]):4096; ports:[31000-32000] (allocated: {})
3: I1125 20:53:26.774230 29055 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/DiskResource_PersistentVolumeTest_BadACLNoPrincipal_0_PpHh3r/meta/slaves/86bca794-82bf-4445-9ea6-a9ff72ead453-S0/slave.info'
3: I1125 20:53:26.774480 29061 hierarchical.cpp:1457] Performed allocation for 1 agents in 160555ns
3: I1125 20:53:26.774734 29055 slave.cpp:1298] Forwarding total oversubscribed resources {}
3: I1125 20:53:26.774953 29069 master.cpp:7091] Received update of agent 86bca794-82bf-4445-9ea6-a9ff72ead453-S0 at slave(900)@172.17.0.2:46464 (0ec1a6f6aad0) with total oversubscribed resources {}
3: I1125 20:53:26.775122 29069 master.cpp:7109] Ignoring update on agent 86bca794-82bf-4445-9ea6-a9ff72ead453-S0 at slave(900)@172.17.0.2:46464 (0ec1a6f6aad0) as it reports no changes
3: W1125 20:53:26.775646 20035 process.cpp:2756] Attempted to spawn already running process version@172.17.0.2:46464
3: I1125 20:53:26.776609 20035 sched.cpp:232] Version: 1.5.0
3: I1125 20:53:26.777355 29059 sched.cpp:336] New master detected at master@172.17.0.2:46464
3: I1125 20:53:26.777454 29059 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1125 20:53:26.777465 29059 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.2:46464
3: I1125 20:53:26.777595 29059 sched.cpp:857] Will retry registration in 1.027182524secs if necessary
3: I1125 20:53:26.777791 29056 master.cpp:2963] Received SUBSCRIBE call for framework 'no-principal' at scheduler-f4097a71-2909-4969-80ad-b0a9c84eb815@172.17.0.2:46464
3: I1125 20:53:26.777885 29056 master.cpp:2280] Authorizing framework principal '' to receive offers for roles '{ default-role }'
3: I1125 20:53:26.778323 29074 master.cpp:3043] Subscribing framework no-principal with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1125 20:53:26.778831 29073 sched.cpp:751] Framework registered with 86bca794-82bf-4445-9ea6-a9ff72ead453-0000
3: I1125 20:53:26.778875 29073 sched.cpp:765] Scheduler::registered took 22255ns
3: I1125 20:53:26.779116 29072 hierarchical.cpp:306] Added framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0000
3: I1125 20:53:26.780360 29072 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.124572ms
3: I1125 20:53:26.781057 29070 master.cpp:8142] Sending 1 offers to framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0000 (no-principal) at scheduler-f4097a71-2909-4969-80ad-b0a9c84eb815@172.17.0.2:46464
3: I1125 20:53:26.781926 29063 sched.cpp:921] Scheduler::resourceOffers took 147447ns
3: I1125 20:53:26.782867 29058 hierarchical.cpp:1457] Performed allocation for 1 agents in 267297ns
3: I1125 20:53:26.785189 29077 master.cpp:10063] Removing offer 86bca794-82bf-4445-9ea6-a9ff72ead453-O0
3: I1125 20:53:26.785362 29077 master.cpp:4230] Processing ACCEPT call for offers: [ 86bca794-82bf-4445-9ea6-a9ff72ead453-O0 ] on agent 86bca794-82bf-4445-9ea6-a9ff72ead453-S0 at slave(900)@172.17.0.2:46464 (0ec1a6f6aad0) for framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0000 (no-principal) at scheduler-f4097a71-2909-4969-80ad-b0a9c84eb815@172.17.0.2:46464
3: I1125 20:53:26.785488 29077 master.cpp:3792] Authorizing principal 'ANY' to create volumes '[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: W1125 20:53:26.786489 29076 master.cpp:2365] Dropping CREATE offer operation from framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0000 (no-principal) at scheduler-f4097a71-2909-4969-80ad-b0a9c84eb815@172.17.0.2:46464: Not authorized to create persistent volumes as ''
3: I1125 20:53:26.787585 29068 hierarchical.cpp:1132] Recovered cpus(allocated: default-role):2; mem(allocated: default-role):2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)]):4096; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)]):4096; ports:[31000-32000], allocated: {}) on agent 86bca794-82bf-4445-9ea6-a9ff72ead453-S0 from framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0000
3: I1125 20:53:26.789252 29071 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.062544ms
3: I1125 20:53:26.789773 29056 master.cpp:8142] Sending 1 offers to framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0000 (no-principal) at scheduler-f4097a71-2909-4969-80ad-b0a9c84eb815@172.17.0.2:46464
3: I1125 20:53:26.790287 29056 sched.cpp:921] Scheduler::resourceOffers took 85746ns
3: I1125 20:53:26.790892 29073 master.cpp:5434] Processing DECLINE call for offers: [ 86bca794-82bf-4445-9ea6-a9ff72ead453-O1 ] for framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0000 (no-principal) at scheduler-f4097a71-2909-4969-80ad-b0a9c84eb815@172.17.0.2:46464
3: W1125 20:53:26.790946 20035 process.cpp:2756] Attempted to spawn already running process version@172.17.0.2:46464
3: I1125 20:53:26.791532 29073 master.cpp:10063] Removing offer 86bca794-82bf-4445-9ea6-a9ff72ead453-O1
3: I1125 20:53:26.791657 29073 master.cpp:3473] Processing SUPPRESS call for framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0000 (no-principal) at scheduler-f4097a71-2909-4969-80ad-b0a9c84eb815@172.17.0.2:46464
3: I1125 20:53:26.791700 20035 sched.cpp:232] Version: 1.5.0
3: I1125 20:53:26.792062 29064 hierarchical.cpp:1132] Recovered cpus(allocated: default-role):2; mem(allocated: default-role):2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)]):4096; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)]):4096; ports:[31000-32000], allocated: {}) on agent 86bca794-82bf-4445-9ea6-a9ff72ead453-S0 from framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0000
3: I1125 20:53:26.792201 29064 hierarchical.cpp:1244] Suppressed offers for roles { default-role } of framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0000
3: I1125 20:53:26.792235 29060 sched.cpp:336] New master detected at master@172.17.0.2:46464
3: I1125 20:53:26.792316 29060 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1125 20:53:26.792330 29060 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.2:46464
3: I1125 20:53:26.792430 29060 sched.cpp:857] Will retry registration in 1.178005742secs if necessary
3: I1125 20:53:26.792598 29058 master.cpp:2963] Received SUBSCRIBE call for framework 'default' at scheduler-567d1b73-2140-46a3-85ad-f012c6cc2919@172.17.0.2:46464
3: I1125 20:53:26.792676 29058 master.cpp:2280] Authorizing framework principal 'test-principal' to receive offers for roles '{ default-role }'
3: I1125 20:53:26.793119 29067 master.cpp:3043] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1125 20:53:26.793539 29069 hierarchical.cpp:306] Added framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0001
3: I1125 20:53:26.793653 29055 sched.cpp:751] Framework registered with 86bca794-82bf-4445-9ea6-a9ff72ead453-0001
3: I1125 20:53:26.793691 29055 sched.cpp:765] Scheduler::registered took 17804ns
3: I1125 20:53:26.794668 29069 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.013973ms
3: I1125 20:53:26.795102 29066 master.cpp:8142] Sending 1 offers to framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0001 (default) at scheduler-567d1b73-2140-46a3-85ad-f012c6cc2919@172.17.0.2:46464
3: I1125 20:53:26.795558 29076 sched.cpp:921] Scheduler::resourceOffers took 87315ns
3: I1125 20:53:26.796219 29068 hierarchical.cpp:1457] Performed allocation for 1 agents in 121924ns
3: I1125 20:53:26.797787 29059 master.cpp:10063] Removing offer 86bca794-82bf-4445-9ea6-a9ff72ead453-O2
3: I1125 20:53:26.797911 29059 master.cpp:4230] Processing ACCEPT call for offers: [ 86bca794-82bf-4445-9ea6-a9ff72ead453-O2 ] on agent 86bca794-82bf-4445-9ea6-a9ff72ead453-S0 at slave(900)@172.17.0.2:46464 (0ec1a6f6aad0) for framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0001 (default) at scheduler-567d1b73-2140-46a3-85ad-f012c6cc2919@172.17.0.2:46464
3: I1125 20:53:26.798095 29059 master.cpp:3792] Authorizing principal 'test-principal' to create volumes '[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: I1125 20:53:26.799681 29075 master.cpp:4706] Applying CREATE operation for volumes [{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}] from framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0001 (default) at scheduler-567d1b73-2140-46a3-85ad-f012c6cc2919@172.17.0.2:46464 to agent 86bca794-82bf-4445-9ea6-a9ff72ead453-S0 at slave(900)@172.17.0.2:46464 (0ec1a6f6aad0)
3: I1125 20:53:26.800202 29075 master.cpp:10008] Sending updated checkpointed resources disk(reservations: [(STATIC,default-role)])[id1:path1]:2048 to agent 86bca794-82bf-4445-9ea6-a9ff72ead453-S0 at slave(900)@172.17.0.2:46464 (0ec1a6f6aad0)
3: I1125 20:53:26.801465 29072 slave.cpp:3594] Updated checkpointed resources from {} to disk(reservations: [(STATIC,default-role)])[id1:path1]:2048
3: I1125 20:53:26.803154 29063 hierarchical.cpp:856] Updated allocation of framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0001 on agent 86bca794-82bf-4445-9ea6-a9ff72ead453-S0 from cpus(allocated: default-role):2; mem(allocated: default-role):2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)]):4096; ports(allocated: default-role):[31000-32000] to cpus(allocated: default-role):2; mem(allocated: default-role):2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)]):2048; ports(allocated: default-role):[31000-32000]; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[id1:path1]:2048
3: I1125 20:53:26.804476 29063 hierarchical.cpp:1132] Recovered cpus(allocated: default-role):2; mem(allocated: default-role):2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)]):2048; ports(allocated: default-role):[31000-32000]; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[id1:path1]:2048 (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)]):2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[id1:path1]:2048, allocated: {}) on agent 86bca794-82bf-4445-9ea6-a9ff72ead453-S0 from framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0001
3: I1125 20:53:26.806324 29060 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.368296ms
3: I1125 20:53:26.807003 29065 master.cpp:8142] Sending 1 offers to framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0001 (default) at scheduler-567d1b73-2140-46a3-85ad-f012c6cc2919@172.17.0.2:46464
3: I1125 20:53:26.807507 29058 sched.cpp:921] Scheduler::resourceOffers took 89510ns
3: I1125 20:53:26.808154 29077 master.cpp:5434] Processing DECLINE call for offers: [ 86bca794-82bf-4445-9ea6-a9ff72ead453-O3 ] for framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0001 (default) at scheduler-567d1b73-2140-46a3-85ad-f012c6cc2919@172.17.0.2:46464
3: I1125 20:53:26.808897 29077 master.cpp:10063] Removing offer 86bca794-82bf-4445-9ea6-a9ff72ead453-O3
3: I1125 20:53:26.809053 29077 master.cpp:3473] Processing SUPPRESS call for framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0001 (default) at scheduler-567d1b73-2140-46a3-85ad-f012c6cc2919@172.17.0.2:46464
3: I1125 20:53:26.809649 29067 hierarchical.cpp:1132] Recovered cpus(allocated: default-role):2; mem(allocated: default-role):2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)]):2048; ports(allocated: default-role):[31000-32000]; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[id1:path1]:2048 (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)]):2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[id1:path1]:2048, allocated: {}) on agent 86bca794-82bf-4445-9ea6-a9ff72ead453-S0 from framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0001
3: I1125 20:53:26.809798 29067 hierarchical.cpp:1244] Suppressed offers for roles { default-role } of framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0001
3: I1125 20:53:26.810087 29055 master.cpp:5539] Processing REVIVE call for framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0000 (no-principal) at scheduler-f4097a71-2909-4969-80ad-b0a9c84eb815@172.17.0.2:46464
3: I1125 20:53:26.810222 29066 hierarchical.cpp:1279] Revived offers for roles { default-role } of framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0000
3: I1125 20:53:26.811652 29066 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.322251ms
3: I1125 20:53:26.812265 29076 master.cpp:8142] Sending 1 offers to framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0000 (no-principal) at scheduler-f4097a71-2909-4969-80ad-b0a9c84eb815@172.17.0.2:46464
3: I1125 20:53:26.812836 29062 sched.cpp:921] Scheduler::resourceOffers took 96320ns
3: I1125 20:53:26.814215 29054 master.cpp:10063] Removing offer 86bca794-82bf-4445-9ea6-a9ff72ead453-O4
3: I1125 20:53:26.814323 29054 master.cpp:4230] Processing ACCEPT call for offers: [ 86bca794-82bf-4445-9ea6-a9ff72ead453-O4 ] on agent 86bca794-82bf-4445-9ea6-a9ff72ead453-S0 at slave(900)@172.17.0.2:46464 (0ec1a6f6aad0) for framework 86bca794-82bf-4445-9ea6-a9ff72ead453-0000 (no-principal) at scheduler-f4097a71-2909-4969-80ad-b0a9c84eb815@172.17.0.2:46464
3: I1125 20:53:26.814432 29054 master.cpp:3844] Authorizing principal 'ANY' to destroy volumes '[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1511640864-32115
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user benjamin.hindman@gmail.com


Jenkins build is back to normal : Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4499

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%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4499/display/redirect?page=changes>