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/10/20 02:03:37 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) #4346

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)/4346/display/redirect?page=changes>

Changes:

[jpeach] Added a `network/ports` isolator skeleton.

[jpeach] Added network ports isolator listen socket utilities.

[jpeach] Added network ports isolator socket utilities tests.

[jpeach] Added socket checking to the network ports isolator.

[jpeach] Configure the `network/ports` isolator watch interval.

[jpeach] Optionally isolate only the agent network ports.

[jpeach] Ignored containers that join CNI networks.

[jpeach] Added the `network/ports` isolator to the Mesos containerizer.

[jpeach] Added basic `network/ports` isolator tests.

[jpeach] Added `network/ports` isolator recovery tests.

[jpeach] Added `network/ports` isolator nested container tests.

------------------------------------------
[...truncated 31.03 MB...]
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/ujewNY/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/ujewNY/master" --zk_session_timeout="10secs"
3: I1020 02:00:35.301120 27987 master.cpp:498] Master allowing unauthenticated frameworks to register
3: I1020 02:00:35.301132 27987 master.cpp:502] Master only allowing authenticated agents to register
3: I1020 02:00:35.301141 27987 master.cpp:508] Master only allowing authenticated HTTP frameworks to register
3: I1020 02:00:35.301161 27987 credentials.hpp:37] Loading credentials for authentication from '/tmp/ujewNY/credentials'
3: I1020 02:00:35.301501 27987 master.cpp:552] Using default 'crammd5' authenticator
3: I1020 02:00:35.301704 27987 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1020 02:00:35.301910 27987 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1020 02:00:35.302135 27987 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1020 02:00:35.302317 27987 master.cpp:631] Authorization enabled
3: W1020 02:00:35.302340 27987 master.cpp:694] The '--roles' flag is deprecated. This flag will be removed in the future. See the Mesos 0.27 upgrade notes for more information
3: I1020 02:00:35.302554 28004 whitelist_watcher.cpp:77] No whitelist given
3: I1020 02:00:35.302603 27992 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1020 02:00:35.305477 27986 master.cpp:2198] Elected as the leading master!
3: I1020 02:00:35.305505 27986 master.cpp:1687] Recovering from registrar
3: I1020 02:00:35.305668 27991 registrar.cpp:347] Recovering registrar
3: I1020 02:00:35.306188 27991 registrar.cpp:391] Successfully fetched the registry (0B) in 0ns
3: I1020 02:00:35.306272 27991 registrar.cpp:495] Applied 1 operations in 21703ns; attempting to update the registry
3: I1020 02:00:35.306751 27988 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1020 02:00:35.306859 27988 registrar.cpp:424] Successfully recovered registrar
3: I1020 02:00:35.307394 27994 master.cpp:1791] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1020 02:00:35.307411 27985 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: W1020 02:00:35.312603 19871 process.cpp:3193] Attempted to spawn already running process files@172.17.0.4:44808
3: I1020 02:00:35.313479 19871 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1020 02:00:35.313953 19871 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1020 02:00:35.314072 19871 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1020 02:00:35.314101 19871 provisioner.cpp:255] Using default backend 'copy'
3: I1020 02:00:35.315945 19871 cluster.cpp:448] Creating default 'local' authorizer
3: I1020 02:00:35.318063 27985 slave.cpp:254] Mesos agent started on (831)@172.17.0.4:44808
3: W1020 02:00:35.318497 19871 process.cpp:3193] Attempted to spawn already running process version@172.17.0.4:44808
3: I1020 02:00:35.318086 27985 slave.cpp:255] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_l7nauF/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_BadACLDropCreateAndDestroy_1_l7nauF/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_l7nauF/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_BadACLDropCreateAndDestroy_1_l7nauF/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_l7nauF/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_l7nauF/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_vF1g0c\/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_vF1g0c\/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_l7nauF" --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_st6cfr" --zk_session_timeout="10secs"
3: I1020 02:00:35.318532 27985 credentials.hpp:86] Loading credential for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_l7nauF/credential'
3: I1020 02:00:35.318697 27985 slave.cpp:287] Agent using credential for: test-principal
3: I1020 02:00:35.318717 27985 credentials.hpp:37] Loading credentials for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_l7nauF/http_credentials'
3: I1020 02:00:35.319025 27985 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1020 02:00:35.319165 27985 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1020 02:00:35.319337 19871 sched.cpp:232] Version: 1.5.0
3: I1020 02:00:35.319437 27985 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1020 02:00:35.319573 27985 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1020 02:00:35.319910 27985 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1020 02:00:35.319973 27984 sched.cpp:336] New master detected at master@172.17.0.4:44808
3: I1020 02:00:35.320049 27985 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1020 02:00:35.320089 27984 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1020 02:00:35.320101 27984 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.4:44808
3: I1020 02:00:35.320219 27984 sched.cpp:853] Will retry registration in 1.955896264secs if necessary
3: I1020 02:00:35.320401 27991 master.cpp:2929] Received SUBSCRIBE call for framework 'default' at scheduler-3ac92834-a7a2-4dd9-a7d6-cc32f3e66697@172.17.0.4:44808
3: I1020 02:00:35.320477 27991 master.cpp:2263] Authorizing framework principal 'test-principal' to receive offers for roles '{ default-role }'
3: I1020 02:00:35.320894 27988 master.cpp:3009] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1020 02:00:35.321560 27988 sched.cpp:747] Framework registered with 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000
3: I1020 02:00:35.321602 27988 sched.cpp:761] Scheduler::registered took 16672ns
3: I1020 02:00:35.321681 27999 hierarchical.cpp:303] Added framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000
3: I1020 02:00:35.321990 27999 hierarchical.cpp:1488] Performed allocation for 0 agents in 107026ns
3: I1020 02:00:35.325496 27985 slave.cpp:585] 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_vF1g0c\/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_vF1g0c\/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: I1020 02:00:35.326228 27985 slave.cpp:593] Agent attributes: [  ]
3: I1020 02:00:35.326244 27985 slave.cpp:602] Agent hostname: 561d479a968e
3: I1020 02:00:35.326469 28007 status_update_manager.cpp:177] Pausing sending status updates
3: I1020 02:00:35.328421 27995 state.cpp:64] Recovering state from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_st6cfr/meta'
3: I1020 02:00:35.328974 27998 status_update_manager.cpp:203] Recovering status update manager
3: I1020 02:00:35.329277 28000 containerizer.cpp:662] Recovering containerizer
3: I1020 02:00:35.331022 27990 provisioner.cpp:416] Provisioner recovery complete
3: I1020 02:00:35.331612 27987 slave.cpp:6310] Finished recovery
3: I1020 02:00:35.332540 28004 slave.cpp:993] New master detected at master@172.17.0.4:44808
3: I1020 02:00:35.332554 27985 status_update_manager.cpp:177] Pausing sending status updates
3: I1020 02:00:35.332623 28004 slave.cpp:1028] Detecting new master
3: I1020 02:00:35.333247 27995 slave.cpp:1055] Authenticating with master master@172.17.0.4:44808
3: I1020 02:00:35.333313 27995 slave.cpp:1064] Using default CRAM-MD5 authenticatee
3: I1020 02:00:35.333621 27998 hierarchical.cpp:1488] Performed allocation for 0 agents in 120822ns
3: I1020 02:00:35.333683 27984 authenticatee.cpp:121] Creating new client SASL connection
3: I1020 02:00:35.334131 27989 master.cpp:7936] Authenticating slave(831)@172.17.0.4:44808
3: I1020 02:00:35.334348 28001 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1499)@172.17.0.4:44808
3: I1020 02:00:35.334826 27994 authenticator.cpp:98] Creating new server SASL connection
3: I1020 02:00:35.335209 28003 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1020 02:00:35.335239 28003 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1020 02:00:35.335360 28003 authenticator.cpp:204] Received SASL authentication start
3: I1020 02:00:35.335420 28003 authenticator.cpp:326] Authentication requires more steps
3: I1020 02:00:35.335541 28003 authenticatee.cpp:259] Received SASL authentication step
3: I1020 02:00:35.335671 28003 authenticator.cpp:232] Received SASL authentication step
3: I1020 02:00:35.335700 28003 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '561d479a968e' server FQDN: '561d479a968e' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1020 02:00:35.335710 28003 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1020 02:00:35.335737 28003 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1020 02:00:35.335758 28003 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '561d479a968e' server FQDN: '561d479a968e' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1020 02:00:35.335767 28003 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1020 02:00:35.335773 28003 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1020 02:00:35.335800 28003 authenticator.cpp:318] Authentication success
3: I1020 02:00:35.335952 28005 authenticatee.cpp:299] Authentication success
3: I1020 02:00:35.335999 27988 master.cpp:7966] Successfully authenticated principal 'test-principal' at slave(831)@172.17.0.4:44808
3: I1020 02:00:35.336035 28003 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1499)@172.17.0.4:44808
3: I1020 02:00:35.336326 27990 slave.cpp:1147] Successfully authenticated with master master@172.17.0.4:44808
3: I1020 02:00:35.336730 27990 slave.cpp:1626] Will retry registration in 17.734336ms if necessary
3: I1020 02:00:35.336962 27996 master.cpp:5801] Received register agent message from slave(831)@172.17.0.4:44808 (561d479a968e)
3: I1020 02:00:35.337098 27996 master.cpp:3838] Authorizing agent with principal 'test-principal'
3: I1020 02:00:35.337498 27985 master.cpp:5861] Authorized registration of agent at slave(831)@172.17.0.4:44808 (561d479a968e)
3: I1020 02:00:35.337644 27985 master.cpp:5954] Registering agent at slave(831)@172.17.0.4:44808 (561d479a968e) with id 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0
3: I1020 02:00:35.338181 28004 registrar.cpp:495] Applied 1 operations in 69653ns; attempting to update the registry
3: I1020 02:00:35.338724 28004 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1020 02:00:35.338949 27998 master.cpp:6001] Admitted agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 at slave(831)@172.17.0.4:44808 (561d479a968e)
3: I1020 02:00:35.339838 27989 slave.cpp:1193] Registered with master master@172.17.0.4:44808; given agent ID 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0
3: I1020 02:00:35.339985 28006 status_update_manager.cpp:184] Resuming sending status updates
3: I1020 02:00:35.339706 27998 master.cpp:6032] Registered agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 at slave(831)@172.17.0.4:44808 (561d479a968e) 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_vF1g0c\/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_vF1g0c\/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: I1020 02:00:35.340240 27989 slave.cpp:1213] Checkpointing SlaveInfo to '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_st6cfr/meta/slaves/01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0/slave.info'
3: I1020 02:00:35.340258 28001 hierarchical.cpp:593] Added agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 (561d479a968e) with cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk2]:2048; ports:[31000-32000] (allocated: {})
3: I1020 02:00:35.340688 27989 slave.cpp:1262] Forwarding total oversubscribed resources {}
3: I1020 02:00:35.340880 27989 master.cpp:6817] Received update of agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 at slave(831)@172.17.0.4:44808 (561d479a968e) with total oversubscribed resources {}
3: I1020 02:00:35.341131 27989 master.cpp:6828] Ignoring update on agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 at slave(831)@172.17.0.4:44808 (561d479a968e) as it reports no changes
3: I1020 02:00:35.342022 28001 hierarchical.cpp:1488] Performed allocation for 1 agents in 1.596297ms
3: I1020 02:00:35.342768 27991 master.cpp:7766] Sending 1 offers to framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000 (default) at scheduler-3ac92834-a7a2-4dd9-a7d6-cc32f3e66697@172.17.0.4:44808
3: I1020 02:00:35.343295 27991 sched.cpp:917] Scheduler::resourceOffers took 97391ns
3: I1020 02:00:35.346069 27988 master.cpp:9389] Removing offer 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-O0
3: I1020 02:00:35.346313 27988 master.cpp:4196] Processing ACCEPT call for offers: [ 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-O0 ] on agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 at slave(831)@172.17.0.4:44808 (561d479a968e) for framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000 (default) at scheduler-3ac92834-a7a2-4dd9-a7d6-cc32f3e66697@172.17.0.4:44808
3: I1020 02:00:35.346547 27988 master.cpp:3758] 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_vF1g0c\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: W1020 02:00:35.347995 27988 master.cpp:2348] Dropping CREATE offer operation from framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000 (default) at scheduler-3ac92834-a7a2-4dd9-a7d6-cc32f3e66697@172.17.0.4:44808: Not authorized to create persistent volumes as 'test-principal'
3: I1020 02:00:35.349858 27996 hierarchical.cpp:1163] 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_vF1g0c/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk2]:2048; ports:[31000-32000], allocated: {}) on agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 from framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000
3: I1020 02:00:35.351948 28002 hierarchical.cpp:1488] Performed allocation for 1 agents in 1.472813ms
3: I1020 02:00:35.352691 27986 master.cpp:7766] Sending 1 offers to framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000 (default) at scheduler-3ac92834-a7a2-4dd9-a7d6-cc32f3e66697@172.17.0.4:44808
3: I1020 02:00:35.353282 27995 sched.cpp:917] Scheduler::resourceOffers took 107711ns
3: W1020 02:00:35.353901 19871 process.cpp:3193] Attempted to spawn already running process version@172.17.0.4:44808
3: I1020 02:00:35.353948 28004 master.cpp:5207] Processing DECLINE call for offers: [ 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-O1 ] for framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000 (default) at scheduler-3ac92834-a7a2-4dd9-a7d6-cc32f3e66697@172.17.0.4:44808
3: I1020 02:00:35.354534 19871 sched.cpp:232] Version: 1.5.0
3: I1020 02:00:35.354820 28004 master.cpp:9389] Removing offer 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-O1
3: I1020 02:00:35.354997 28004 master.cpp:3439] Processing SUPPRESS call for framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000 (default) at scheduler-3ac92834-a7a2-4dd9-a7d6-cc32f3e66697@172.17.0.4:44808
3: I1020 02:00:35.355062 27989 sched.cpp:336] New master detected at master@172.17.0.4:44808
3: I1020 02:00:35.355162 27989 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1020 02:00:35.355182 27989 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.4:44808
3: I1020 02:00:35.355293 27989 sched.cpp:853] Will retry registration in 741.247548ms if necessary
3: I1020 02:00:35.355479 28001 master.cpp:2929] Received SUBSCRIBE call for framework 'creator-framework' at scheduler-bd471cdc-130e-43a9-aa03-dea158c832fd@172.17.0.4:44808
3: I1020 02:00:35.355545 28001 master.cpp:2263] Authorizing framework principal 'creator-principal' to receive offers for roles '{ default-role }'
3: I1020 02:00:35.355856 27994 hierarchical.cpp:1163] 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_vF1g0c/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk2]:2048; ports:[31000-32000], allocated: {}) on agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 from framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000
3: I1020 02:00:35.355978 27991 master.cpp:3009] Subscribing framework creator-framework with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1020 02:00:35.356026 27994 hierarchical.cpp:1275] Suppressed offers for roles { default-role } of framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000
3: I1020 02:00:35.356432 28007 hierarchical.cpp:303] Added framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001
3: I1020 02:00:35.356498 28003 sched.cpp:747] Framework registered with 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001
3: I1020 02:00:35.356555 28003 sched.cpp:761] Scheduler::registered took 25295ns
3: I1020 02:00:35.358767 28007 hierarchical.cpp:1488] Performed allocation for 1 agents in 2.129118ms
3: I1020 02:00:35.359791 27987 master.cpp:7766] Sending 1 offers to framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001 (creator-framework) at scheduler-bd471cdc-130e-43a9-aa03-dea158c832fd@172.17.0.4:44808
3: I1020 02:00:35.360481 27990 sched.cpp:917] Scheduler::resourceOffers took 123712ns
3: I1020 02:00:35.361285 27988 hierarchical.cpp:1488] Performed allocation for 1 agents in 220088ns
3: I1020 02:00:35.363265 28002 master.cpp:9389] Removing offer 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-O2
3: I1020 02:00:35.363389 28002 master.cpp:4196] Processing ACCEPT call for offers: [ 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-O2 ] on agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 at slave(831)@172.17.0.4:44808 (561d479a968e) for framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001 (creator-framework) at scheduler-bd471cdc-130e-43a9-aa03-dea158c832fd@172.17.0.4:44808
3: I1020 02:00:35.363538 28002 master.cpp:3758] 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_vF1g0c\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: I1020 02:00:35.365069 28006 master.cpp:4639] 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_vF1g0c\/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 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001 (creator-framework) at scheduler-bd471cdc-130e-43a9-aa03-dea158c832fd@172.17.0.4:44808 to agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 at slave(831)@172.17.0.4:44808 (561d479a968e)
3: I1020 02:00:35.365937 28006 master.cpp:9335] Sending updated checkpointed resources disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk1,id1:path1]:2048 to agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 at slave(831)@172.17.0.4:44808 (561d479a968e)
3: I1020 02:00:35.367158 27998 slave.cpp:3519] Updated checkpointed resources from {} to disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk1,id1:path1]:2048
3: I1020 02:00:35.369964 28004 hierarchical.cpp:887] Updated allocation of framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001 on agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-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_vF1g0c/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/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_vF1g0c/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk1,id1:path1]:2048
3: I1020 02:00:35.371480 28004 hierarchical.cpp:1163] 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_vF1g0c/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk1,id1:path1]:2048, allocated: {}) on agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 from framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001
3: I1020 02:00:35.374105 27992 hierarchical.cpp:1488] Performed allocation for 1 agents in 1.906104ms
3: I1020 02:00:35.375149 28001 master.cpp:7766] Sending 1 offers to framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001 (creator-framework) at scheduler-bd471cdc-130e-43a9-aa03-dea158c832fd@172.17.0.4:44808
3: I1020 02:00:35.375965 28005 sched.cpp:917] Scheduler::resourceOffers took 140148ns
3: I1020 02:00:35.376724 27991 master.cpp:5207] Processing DECLINE call for offers: [ 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-O3 ] for framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001 (creator-framework) at scheduler-bd471cdc-130e-43a9-aa03-dea158c832fd@172.17.0.4:44808
3: I1020 02:00:35.377683 27991 master.cpp:9389] Removing offer 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-O3
3: I1020 02:00:35.377823 27991 master.cpp:3439] Processing SUPPRESS call for framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001 (creator-framework) at scheduler-bd471cdc-130e-43a9-aa03-dea158c832fd@172.17.0.4:44808
3: I1020 02:00:35.378868 27999 hierarchical.cpp:1163] 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_vF1g0c/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk1,id1:path1]:2048, allocated: {}) on agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 from framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001
3: I1020 02:00:35.379079 27999 hierarchical.cpp:1275] Suppressed offers for roles { default-role } of framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001
3: I1020 02:00:35.379552 28003 master.cpp:5312] Processing REVIVE call for framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000 (default) at scheduler-3ac92834-a7a2-4dd9-a7d6-cc32f3e66697@172.17.0.4:44808
3: I1020 02:00:35.379758 27987 hierarchical.cpp:1310] Revived offers for roles { default-role } of framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000
3: I1020 02:00:35.381857 27987 hierarchical.cpp:1488] Performed allocation for 1 agents in 1.964957ms
3: I1020 02:00:35.382766 27990 master.cpp:7766] Sending 1 offers to framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000 (default) at scheduler-3ac92834-a7a2-4dd9-a7d6-cc32f3e66697@172.17.0.4:44808
3: I1020 02:00:35.383522 27996 sched.cpp:917] Scheduler::resourceOffers took 144821ns
3: I1020 02:00:35.385284 27997 master.cpp:9389] Removing offer 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-O4
3: I1020 02:00:35.385412 27997 master.cpp:4196] Processing ACCEPT call for offers: [ 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-O4 ] on agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 at slave(831)@172.17.0.4:44808 (561d479a968e) for framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000 (default) at scheduler-3ac92834-a7a2-4dd9-a7d6-cc32f3e66697@172.17.0.4:44808
3: I1020 02:00:35.385548 27997 master.cpp:3810] 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_vF1g0c\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: W1020 02:00:35.386507 27997 master.cpp:2348] Dropping DESTROY offer operation from framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000 (default) at scheduler-3ac92834-a7a2-4dd9-a7d6-cc32f3e66697@172.17.0.4:44808: Not authorized to destroy persistent volumes as 'test-principal'
3: I1020 02:00:35.388101 27984 hierarchical.cpp:1163] 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_vF1g0c/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk1,id1:path1]:2048, allocated: {}) on agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 from framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000
3: I1020 02:00:35.390631 28006 hierarchical.cpp:1488] Performed allocation for 1 agents in 1.878999ms
3: I1020 02:00:35.391355 27998 master.cpp:7766] Sending 1 offers to framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000 (default) at scheduler-3ac92834-a7a2-4dd9-a7d6-cc32f3e66697@172.17.0.4:44808
3: I1020 02:00:35.391911 28004 sched.cpp:917] Scheduler::resourceOffers took 100959ns
3: I1020 02:00:35.392222 19871 sched.cpp:2005] Asked to stop the driver
3: I1020 02:00:35.392339 27989 sched.cpp:1187] Stopping framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000
3: I1020 02:00:35.392666 27992 master.cpp:8447] Processing TEARDOWN call for framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000 (default) at scheduler-3ac92834-a7a2-4dd9-a7d6-cc32f3e66697@172.17.0.4:44808
3: I1020 02:00:35.392704 27992 master.cpp:8459] Removing framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000 (default) at scheduler-3ac92834-a7a2-4dd9-a7d6-cc32f3e66697@172.17.0.4:44808
3: I1020 02:00:35.392715 27992 master.cpp:3299] Deactivating framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000 (default) at scheduler-3ac92834-a7a2-4dd9-a7d6-cc32f3e66697@172.17.0.4:44808
3: I1020 02:00:35.392729 19871 sched.cpp:2005] Asked to stop the driver
3: I1020 02:00:35.392817 27994 hierarchical.cpp:412] Deactivated framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000
3: I1020 02:00:35.392846 27999 sched.cpp:1187] Stopping framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001
3: I1020 02:00:35.393878 27992 master.cpp:9389] Removing offer 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-O5
3: I1020 02:00:35.394083 27997 slave.cpp:3211] Asked to shut down framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000 by master@172.17.0.4:44808
3: I1020 02:00:35.394110 27997 slave.cpp:3226] Cannot shut down unknown framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000
3: I1020 02:00:35.394429 27992 master.cpp:8447] Processing TEARDOWN call for framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001 (creator-framework) at scheduler-bd471cdc-130e-43a9-aa03-dea158c832fd@172.17.0.4:44808
3: I1020 02:00:35.394461 27992 master.cpp:8459] Removing framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001 (creator-framework) at scheduler-bd471cdc-130e-43a9-aa03-dea158c832fd@172.17.0.4:44808
3: I1020 02:00:35.394474 27992 master.cpp:3299] Deactivating framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001 (creator-framework) at scheduler-bd471cdc-130e-43a9-aa03-dea158c832fd@172.17.0.4:44808
3: I1020 02:00:35.394670 27994 slave.cpp:3211] Asked to shut down framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001 by master@172.17.0.4:44808
3: I1020 02:00:35.394701 27994 slave.cpp:3226] Cannot shut down unknown framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001
3: I1020 02:00:35.394784 28003 hierarchical.cpp:1163] 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_vF1g0c/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_vF1g0c/disk1,id1:path1]:2048, allocated: {}) on agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 from framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000
3: I1020 02:00:35.395125 28003 hierarchical.cpp:355] Removed framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0000
3: I1020 02:00:35.395218 28003 hierarchical.cpp:412] Deactivated framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001
3: I1020 02:00:35.395562 28003 hierarchical.cpp:355] Removed framework 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-0001
3: I1020 02:00:35.395808 19871 slave.cpp:869] Agent terminating
3: I1020 02:00:35.396003 27984 master.cpp:1303] Agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 at slave(831)@172.17.0.4:44808 (561d479a968e) disconnected
3: I1020 02:00:35.396039 27984 master.cpp:3336] Disconnecting agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 at slave(831)@172.17.0.4:44808 (561d479a968e)
3: I1020 02:00:35.396096 27984 master.cpp:3355] Deactivating agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 at slave(831)@172.17.0.4:44808 (561d479a968e)
3: I1020 02:00:35.396194 28005 hierarchical.cpp:690] Agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0 deactivated
3: I1020 02:00:35.401772 19871 master.cpp:1145] Master terminating
3: I1020 02:00:35.403401 28007 hierarchical.cpp:626] Removed agent 01cbe334-ef9c-411e-8e1d-9d92a1cb1ef8-S0
3: [       OK ] DiskResource/PersistentVolumeTest.BadACLDropCreateAndDestroy/1 (111 ms)
3: [----------] 34 tests from DiskResource/PersistentVolumeTest (12323 ms total)
3: 
3: [----------] Global test environment tear-down
3: [==========] 1657 tests from 180 test cases ran. (536957 ms total)
3: [  PASSED  ] 1656 tests.
3: [  FAILED  ] 1 test, listed below:
3: [  FAILED  ] MasterSlaveReconciliationTest.ReconcileRace
3: 
3:  1 FAILED TEST
3:   YOU HAVE 21 DISABLED TESTS
3: 
3: I1020 02:00:35.473898 28008 process.cpp:1067] Failed to accept socket: future discarded
3/3 Test #3: MesosTests .......................***Failed  541.76 sec

67% tests passed, 1 tests failed out of 3

Total Test time (real) = 581.83 sec

The following tests FAILED:
	  3 - MesosTests (Failed)
make[3]: Leaving directory `/mesos/build'
make[2]: Leaving directory `/mesos/build'
make[1]: Leaving directory `/mesos/build'
+ docker rmi mesos-1508462080-17741
Untagged: mesos-1508462080-17741:latest
Deleted: sha256:2f8c69604457e917f310f20d6388db77a7bbbd88686b7cffab5e11111d813f9b
Deleted: sha256:a20e02678c10ea1475502338189fc513aa2018db6530224a1936b246d01a0dab
Deleted: sha256:06cf49c6888a06214605753bb37b8286fb6a260608ee81fcd6b0c2270dd89ecb
Deleted: sha256:bd74306bd7b6b30746293ab2e69b1a93ae24ddf343bae1aeab832fe65ac2c922
Deleted: sha256:a823de9cb7e5f0eca4ffbe67dfa0ffc0d07fac2d913f3cb83f4fb5f0bd7fc388
Deleted: sha256:9444adeb1bd177e51c334fd709d8c7303bf63373f65c385446e5eacf505150ba
Deleted: sha256:7e4c207490694095626e93edb6f0ab37d1503d3faa82dacf396e33fe8c5fc300
Deleted: sha256:105cf3a41b0c22938f5ef93366a3eb3a047a0a3eb6760c313715e0fa0ef7d0e9
Deleted: sha256:d1d05412965b86f83e9c186033dc63164eaa4b64afe2046ddaae95dcb19d1ef6
Deleted: sha256:5535f010c4f5bf54cbc3a82f259880a0fcc73d34cac3f52e7435c369ae609512
Deleted: sha256:6d025fe704444a43d9418ce2f5b1982066198efa621b581d8429ba18fab7db4b
Deleted: sha256:62cdc312a67f9e5f65ce9e40d448a841882317a40ea121871360b326755602bf
Deleted: sha256:846b94ab4e146aaaf92dc04bf2aad4c83a360e35d4e6d15e0d3878252717dea9
Deleted: sha256:f75e8ac3746f0cc5a2db7f08c002d20f66ae4d27153bccaee4b4e2b8a064ea66
Deleted: sha256:ec0c1762e7c33e687a5660a44f3c3bbf0561144aa7a74b9dd8f87f07112619c8
Deleted: sha256:c4c3400eeaad05d9565d91e6184b177ab4d68d7a3cae462c286ef3fcf087d147
Deleted: sha256:594d66579bb1480f4cf8c431ee257de5a7dc7b6bd6b37ee8ba70ff60897903d5
Deleted: sha256:83ff63bf039b4f58aec2d05b1cc41c1575ffc4fa1db4ab5207754f041b31e53e
Deleted: sha256:4af023d8403bbcb2fbb929594795f7da04415c70d21bb0b072e786700fd686bb
Deleted: sha256:5568d4977af089ea3f28283760ff90ff6c2e6170564127c0c72899200322a127
Deleted: sha256:50959e8d63bdd45c89abebd83cb7bf4ea87d3fbb482688bb38132bdd444974f5
Deleted: sha256:8ff86013e397560f94269c49f28e7b408377395e9afe01fd095af2bb0a31ceea
Deleted: sha256:f3a2dd3a069691efe98ee7e6ff8113bce85e348024e876ded4920fdc820ecd9a
Deleted: sha256:20971d47d738ebf6977c7b295b7ee433969ee1f5569b0067a4b47714d532bf2f
Deleted: sha256:ffceed57a748ef366e423db6af63050d2b6c9449da06ee2f77b1e2d946161378
Deleted: sha256:0d132608ad25ff686d1b9cccd818005d3701942dfb16f71020611318c2070964
Deleted: sha256:8edc71683cd274c0c57a83b22f92bdb4bfd7403d4d752969a571ab9d4d07063a
Deleted: sha256:5b31a30b618975dcc5a016a2193720eb3be8d1a6da99d87e2024f525cb0fd450
Build step 'Execute shell' marked build as failure


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) #4348

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)/4348/display/redirect?page=changes>


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) #4347

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)/4347/display/redirect>

------------------------------------------
[...truncated 31.02 MB...]
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/eLqi3g/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/eLqi3g/master" --zk_session_timeout="10secs"
3: I1020 04:29:46.267737 25347 master.cpp:498] Master allowing unauthenticated frameworks to register
3: I1020 04:29:46.267748 25347 master.cpp:502] Master only allowing authenticated agents to register
3: I1020 04:29:46.267755 25347 master.cpp:508] Master only allowing authenticated HTTP frameworks to register
3: I1020 04:29:46.267761 25347 credentials.hpp:37] Loading credentials for authentication from '/tmp/eLqi3g/credentials'
3: I1020 04:29:46.268096 25347 master.cpp:552] Using default 'crammd5' authenticator
3: I1020 04:29:46.268256 25347 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1020 04:29:46.268448 25347 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1020 04:29:46.268605 25347 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1020 04:29:46.268759 25347 master.cpp:631] Authorization enabled
3: W1020 04:29:46.268774 25347 master.cpp:694] The '--roles' flag is deprecated. This flag will be removed in the future. See the Mesos 0.27 upgrade notes for more information
3: I1020 04:29:46.268985 25341 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1020 04:29:46.269002 25337 whitelist_watcher.cpp:77] No whitelist given
3: I1020 04:29:46.272256 25333 master.cpp:2198] Elected as the leading master!
3: I1020 04:29:46.272279 25333 master.cpp:1687] Recovering from registrar
3: I1020 04:29:46.272451 25345 registrar.cpp:347] Recovering registrar
3: I1020 04:29:46.273092 25345 registrar.cpp:391] Successfully fetched the registry (0B) in 0ns
3: I1020 04:29:46.273187 25345 registrar.cpp:495] Applied 1 operations in 26193ns; attempting to update the registry
3: I1020 04:29:46.273684 25345 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1020 04:29:46.273788 25345 registrar.cpp:424] Successfully recovered registrar
3: I1020 04:29:46.274137 25341 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: I1020 04:29:46.274137 25337 master.cpp:1791] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: W1020 04:29:46.278859 19143 process.cpp:3193] Attempted to spawn already running process files@172.17.0.4:56621
3: I1020 04:29:46.279661 19143 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1020 04:29:46.280091 19143 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1020 04:29:46.280208 19143 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1020 04:29:46.280241 19143 provisioner.cpp:255] Using default backend 'copy'
3: I1020 04:29:46.281936 19143 cluster.cpp:448] Creating default 'local' authorizer
3: I1020 04:29:46.283824 25339 slave.cpp:254] Mesos agent started on (831)@172.17.0.4:56621
3: W1020 04:29:46.284257 19143 process.cpp:3193] Attempted to spawn already running process version@172.17.0.4:56621
3: I1020 04:29:46.283843 25339 slave.cpp:255] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_Rqkk1a/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_BadACLDropCreateAndDestroy_1_Rqkk1a/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_Rqkk1a/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_BadACLDropCreateAndDestroy_1_Rqkk1a/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_Rqkk1a/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_Rqkk1a/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_blZQlU\/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_blZQlU\/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_Rqkk1a" --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_Ri7zGx" --zk_session_timeout="10secs"
3: I1020 04:29:46.284374 25339 credentials.hpp:86] Loading credential for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_Rqkk1a/credential'
3: I1020 04:29:46.284567 25339 slave.cpp:287] Agent using credential for: test-principal
3: I1020 04:29:46.284622 25339 credentials.hpp:37] Loading credentials for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_Rqkk1a/http_credentials'
3: I1020 04:29:46.284934 25339 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1020 04:29:46.285071 25339 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1020 04:29:46.285223 19143 sched.cpp:232] Version: 1.5.0
3: I1020 04:29:46.285341 25339 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1020 04:29:46.285490 25339 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1020 04:29:46.285744 25339 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1020 04:29:46.285889 25339 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1020 04:29:46.285996 25348 sched.cpp:336] New master detected at master@172.17.0.4:56621
3: I1020 04:29:46.286233 25348 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1020 04:29:46.286252 25348 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.4:56621
3: I1020 04:29:46.286450 25348 sched.cpp:853] Will retry registration in 881.461763ms if necessary
3: I1020 04:29:46.286643 25335 master.cpp:2929] Received SUBSCRIBE call for framework 'default' at scheduler-4a91827f-30ca-44bd-86b3-8f8005d48abd@172.17.0.4:56621
3: I1020 04:29:46.286723 25335 master.cpp:2263] Authorizing framework principal 'test-principal' to receive offers for roles '{ default-role }'
3: I1020 04:29:46.287214 25345 master.cpp:3009] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1020 04:29:46.287988 25333 hierarchical.cpp:303] Added framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000
3: I1020 04:29:46.288241 25333 hierarchical.cpp:1488] Performed allocation for 0 agents in 77248ns
3: I1020 04:29:46.288779 25345 sched.cpp:747] Framework registered with d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000
3: I1020 04:29:46.288882 25345 sched.cpp:761] Scheduler::registered took 25766ns
3: I1020 04:29:46.289880 25339 slave.cpp:585] 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_blZQlU\/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_blZQlU\/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: I1020 04:29:46.290249 25339 slave.cpp:593] Agent attributes: [  ]
3: I1020 04:29:46.290262 25339 slave.cpp:602] Agent hostname: 385e4b4d6cf2
3: I1020 04:29:46.290451 25342 status_update_manager.cpp:177] Pausing sending status updates
3: I1020 04:29:46.291893 25348 state.cpp:64] Recovering state from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_Ri7zGx/meta'
3: I1020 04:29:46.292215 25346 status_update_manager.cpp:203] Recovering status update manager
3: I1020 04:29:46.292426 25344 containerizer.cpp:662] Recovering containerizer
3: I1020 04:29:46.293812 25337 provisioner.cpp:416] Provisioner recovery complete
3: I1020 04:29:46.294090 25338 slave.cpp:6310] Finished recovery
3: I1020 04:29:46.294766 25345 status_update_manager.cpp:177] Pausing sending status updates
3: I1020 04:29:46.294802 25340 slave.cpp:993] New master detected at master@172.17.0.4:56621
3: I1020 04:29:46.294893 25340 slave.cpp:1028] Detecting new master
3: I1020 04:29:46.295315 25341 slave.cpp:1055] Authenticating with master master@172.17.0.4:56621
3: I1020 04:29:46.295380 25341 slave.cpp:1064] Using default CRAM-MD5 authenticatee
3: I1020 04:29:46.295763 25341 authenticatee.cpp:121] Creating new client SASL connection
3: I1020 04:29:46.295837 25342 hierarchical.cpp:1488] Performed allocation for 0 agents in 68848ns
3: I1020 04:29:46.296038 25339 master.cpp:7936] Authenticating slave(831)@172.17.0.4:56621
3: I1020 04:29:46.296216 25348 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1499)@172.17.0.4:56621
3: I1020 04:29:46.296510 25337 authenticator.cpp:98] Creating new server SASL connection
3: I1020 04:29:46.296711 25346 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1020 04:29:46.296735 25346 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1020 04:29:46.296852 25346 authenticator.cpp:204] Received SASL authentication start
3: I1020 04:29:46.296926 25346 authenticator.cpp:326] Authentication requires more steps
3: I1020 04:29:46.297040 25346 authenticatee.cpp:259] Received SASL authentication step
3: I1020 04:29:46.297180 25347 authenticator.cpp:232] Received SASL authentication step
3: I1020 04:29:46.297212 25347 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '385e4b4d6cf2' server FQDN: '385e4b4d6cf2' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1020 04:29:46.297268 25347 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1020 04:29:46.297313 25347 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1020 04:29:46.297336 25347 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '385e4b4d6cf2' server FQDN: '385e4b4d6cf2' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1020 04:29:46.297348 25347 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1020 04:29:46.297356 25347 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1020 04:29:46.297372 25347 authenticator.cpp:318] Authentication success
3: I1020 04:29:46.297464 25345 authenticatee.cpp:299] Authentication success
3: I1020 04:29:46.297534 25340 master.cpp:7966] Successfully authenticated principal 'test-principal' at slave(831)@172.17.0.4:56621
3: I1020 04:29:46.297585 25343 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1499)@172.17.0.4:56621
3: I1020 04:29:46.297922 25336 slave.cpp:1147] Successfully authenticated with master master@172.17.0.4:56621
3: I1020 04:29:46.298249 25336 slave.cpp:1626] Will retry registration in 12.501537ms if necessary
3: I1020 04:29:46.298527 25344 master.cpp:5801] Received register agent message from slave(831)@172.17.0.4:56621 (385e4b4d6cf2)
3: I1020 04:29:46.298662 25344 master.cpp:3838] Authorizing agent with principal 'test-principal'
3: I1020 04:29:46.299149 25339 master.cpp:5861] Authorized registration of agent at slave(831)@172.17.0.4:56621 (385e4b4d6cf2)
3: I1020 04:29:46.299293 25339 master.cpp:5954] Registering agent at slave(831)@172.17.0.4:56621 (385e4b4d6cf2) with id d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0
3: I1020 04:29:46.299844 25348 registrar.cpp:495] Applied 1 operations in 73800ns; attempting to update the registry
3: I1020 04:29:46.300606 25348 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1020 04:29:46.300956 25348 master.cpp:6001] Admitted agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 at slave(831)@172.17.0.4:56621 (385e4b4d6cf2)
3: I1020 04:29:46.302167 25341 slave.cpp:1193] Registered with master master@172.17.0.4:56621; given agent ID d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0
3: I1020 04:29:46.302285 25343 status_update_manager.cpp:184] Resuming sending status updates
3: I1020 04:29:46.302541 25341 slave.cpp:1213] Checkpointing SlaveInfo to '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_Ri7zGx/meta/slaves/d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0/slave.info'
3: I1020 04:29:46.302073 25348 master.cpp:6032] Registered agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 at slave(831)@172.17.0.4:56621 (385e4b4d6cf2) 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_blZQlU\/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_blZQlU\/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: I1020 04:29:46.302925 25335 hierarchical.cpp:593] Added agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 (385e4b4d6cf2) with cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk2]:2048; ports:[31000-32000] (allocated: {})
3: I1020 04:29:46.302971 25341 slave.cpp:1262] Forwarding total oversubscribed resources {}
3: I1020 04:29:46.303169 25341 master.cpp:6817] Received update of agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 at slave(831)@172.17.0.4:56621 (385e4b4d6cf2) with total oversubscribed resources {}
3: I1020 04:29:46.303423 25341 master.cpp:6828] Ignoring update on agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 at slave(831)@172.17.0.4:56621 (385e4b4d6cf2) as it reports no changes
3: I1020 04:29:46.305404 25335 hierarchical.cpp:1488] Performed allocation for 1 agents in 2.258467ms
3: I1020 04:29:46.306095 25344 master.cpp:7766] Sending 1 offers to framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000 (default) at scheduler-4a91827f-30ca-44bd-86b3-8f8005d48abd@172.17.0.4:56621
3: I1020 04:29:46.306792 25342 sched.cpp:917] Scheduler::resourceOffers took 146543ns
3: I1020 04:29:46.308843 25337 master.cpp:9389] Removing offer d2a32fd3-4264-44b8-a60e-f855d953f4fd-O0
3: I1020 04:29:46.308984 25337 master.cpp:4196] Processing ACCEPT call for offers: [ d2a32fd3-4264-44b8-a60e-f855d953f4fd-O0 ] on agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 at slave(831)@172.17.0.4:56621 (385e4b4d6cf2) for framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000 (default) at scheduler-4a91827f-30ca-44bd-86b3-8f8005d48abd@172.17.0.4:56621
3: I1020 04:29:46.309161 25337 master.cpp:3758] 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_blZQlU\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: W1020 04:29:46.310379 25337 master.cpp:2348] Dropping CREATE offer operation from framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000 (default) at scheduler-4a91827f-30ca-44bd-86b3-8f8005d48abd@172.17.0.4:56621: Not authorized to create persistent volumes as 'test-principal'
3: I1020 04:29:46.311978 25345 hierarchical.cpp:1163] 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_blZQlU/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk2]:2048; ports:[31000-32000], allocated: {}) on agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 from framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000
3: I1020 04:29:46.314518 25343 hierarchical.cpp:1488] Performed allocation for 1 agents in 2.076249ms
3: I1020 04:29:46.315294 25348 master.cpp:7766] Sending 1 offers to framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000 (default) at scheduler-4a91827f-30ca-44bd-86b3-8f8005d48abd@172.17.0.4:56621
3: I1020 04:29:46.315937 25347 sched.cpp:917] Scheduler::resourceOffers took 132583ns
3: W1020 04:29:46.316547 19143 process.cpp:3193] Attempted to spawn already running process version@172.17.0.4:56621
3: I1020 04:29:46.316551 25335 master.cpp:5207] Processing DECLINE call for offers: [ d2a32fd3-4264-44b8-a60e-f855d953f4fd-O1 ] for framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000 (default) at scheduler-4a91827f-30ca-44bd-86b3-8f8005d48abd@172.17.0.4:56621
3: I1020 04:29:46.317178 19143 sched.cpp:232] Version: 1.5.0
3: I1020 04:29:46.317680 25335 master.cpp:9389] Removing offer d2a32fd3-4264-44b8-a60e-f855d953f4fd-O1
3: I1020 04:29:46.317885 25335 master.cpp:3439] Processing SUPPRESS call for framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000 (default) at scheduler-4a91827f-30ca-44bd-86b3-8f8005d48abd@172.17.0.4:56621
3: I1020 04:29:46.317972 25338 sched.cpp:336] New master detected at master@172.17.0.4:56621
3: I1020 04:29:46.318135 25338 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1020 04:29:46.318228 25338 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.4:56621
3: I1020 04:29:46.318423 25338 sched.cpp:853] Will retry registration in 339.250944ms if necessary
3: I1020 04:29:46.318698 25346 master.cpp:2929] Received SUBSCRIBE call for framework 'creator-framework' at scheduler-bef8033b-bc03-45d2-978d-91a044d1ec65@172.17.0.4:56621
3: I1020 04:29:46.318799 25346 master.cpp:2263] Authorizing framework principal 'creator-principal' to receive offers for roles '{ default-role }'
3: I1020 04:29:46.319267 25337 master.cpp:3009] Subscribing framework creator-framework with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1020 04:29:46.319324 25342 hierarchical.cpp:1163] 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_blZQlU/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk2]:2048; ports:[31000-32000], allocated: {}) on agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 from framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000
3: I1020 04:29:46.319507 25342 hierarchical.cpp:1275] Suppressed offers for roles { default-role } of framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000
3: I1020 04:29:46.319708 25345 hierarchical.cpp:303] Added framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001
3: I1020 04:29:46.319888 25343 sched.cpp:747] Framework registered with d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001
3: I1020 04:29:46.319936 25343 sched.cpp:761] Scheduler::registered took 23980ns
3: I1020 04:29:46.321523 25345 hierarchical.cpp:1488] Performed allocation for 1 agents in 1.696058ms
3: I1020 04:29:46.322192 25348 master.cpp:7766] Sending 1 offers to framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001 (creator-framework) at scheduler-bef8033b-bc03-45d2-978d-91a044d1ec65@172.17.0.4:56621
3: I1020 04:29:46.322813 25347 sched.cpp:917] Scheduler::resourceOffers took 129152ns
3: I1020 04:29:46.323367 25344 hierarchical.cpp:1488] Performed allocation for 1 agents in 105535ns
3: I1020 04:29:46.325516 25335 master.cpp:9389] Removing offer d2a32fd3-4264-44b8-a60e-f855d953f4fd-O2
3: I1020 04:29:46.325647 25335 master.cpp:4196] Processing ACCEPT call for offers: [ d2a32fd3-4264-44b8-a60e-f855d953f4fd-O2 ] on agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 at slave(831)@172.17.0.4:56621 (385e4b4d6cf2) for framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001 (creator-framework) at scheduler-bef8033b-bc03-45d2-978d-91a044d1ec65@172.17.0.4:56621
3: I1020 04:29:46.325814 25335 master.cpp:3758] 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_blZQlU\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: I1020 04:29:46.327714 25335 master.cpp:4639] 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_blZQlU\/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 d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001 (creator-framework) at scheduler-bef8033b-bc03-45d2-978d-91a044d1ec65@172.17.0.4:56621 to agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 at slave(831)@172.17.0.4:56621 (385e4b4d6cf2)
3: I1020 04:29:46.328492 25335 master.cpp:9335] Sending updated checkpointed resources disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk1,id1:path1]:2048 to agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 at slave(831)@172.17.0.4:56621 (385e4b4d6cf2)
3: I1020 04:29:46.330101 25337 slave.cpp:3519] Updated checkpointed resources from {} to disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk1,id1:path1]:2048
3: I1020 04:29:46.331899 25336 hierarchical.cpp:887] Updated allocation of framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001 on agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-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_blZQlU/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/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_blZQlU/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk1,id1:path1]:2048
3: I1020 04:29:46.333211 25336 hierarchical.cpp:1163] 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_blZQlU/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk1,id1:path1]:2048, allocated: {}) on agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 from framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001
3: I1020 04:29:46.335609 25345 hierarchical.cpp:1488] Performed allocation for 1 agents in 1.828172ms
3: I1020 04:29:46.336233 25348 master.cpp:7766] Sending 1 offers to framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001 (creator-framework) at scheduler-bef8033b-bc03-45d2-978d-91a044d1ec65@172.17.0.4:56621
3: I1020 04:29:46.336921 25347 sched.cpp:917] Scheduler::resourceOffers took 140253ns
3: I1020 04:29:46.337543 25339 master.cpp:5207] Processing DECLINE call for offers: [ d2a32fd3-4264-44b8-a60e-f855d953f4fd-O3 ] for framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001 (creator-framework) at scheduler-bef8033b-bc03-45d2-978d-91a044d1ec65@172.17.0.4:56621
3: I1020 04:29:46.338784 25339 master.cpp:9389] Removing offer d2a32fd3-4264-44b8-a60e-f855d953f4fd-O3
3: I1020 04:29:46.338953 25339 master.cpp:3439] Processing SUPPRESS call for framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001 (creator-framework) at scheduler-bef8033b-bc03-45d2-978d-91a044d1ec65@172.17.0.4:56621
3: I1020 04:29:46.339193 25344 hierarchical.cpp:1163] 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_blZQlU/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk1,id1:path1]:2048, allocated: {}) on agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 from framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001
3: I1020 04:29:46.339362 25344 hierarchical.cpp:1275] Suppressed offers for roles { default-role } of framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001
3: I1020 04:29:46.339706 25340 master.cpp:5312] Processing REVIVE call for framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000 (default) at scheduler-4a91827f-30ca-44bd-86b3-8f8005d48abd@172.17.0.4:56621
3: I1020 04:29:46.339859 25338 hierarchical.cpp:1310] Revived offers for roles { default-role } of framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000
3: I1020 04:29:46.341277 25338 hierarchical.cpp:1488] Performed allocation for 1 agents in 1.287707ms
3: I1020 04:29:46.341953 25346 master.cpp:7766] Sending 1 offers to framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000 (default) at scheduler-4a91827f-30ca-44bd-86b3-8f8005d48abd@172.17.0.4:56621
3: I1020 04:29:46.342594 25334 sched.cpp:917] Scheduler::resourceOffers took 124799ns
3: I1020 04:29:46.344681 25335 master.cpp:9389] Removing offer d2a32fd3-4264-44b8-a60e-f855d953f4fd-O4
3: I1020 04:29:46.344822 25335 master.cpp:4196] Processing ACCEPT call for offers: [ d2a32fd3-4264-44b8-a60e-f855d953f4fd-O4 ] on agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 at slave(831)@172.17.0.4:56621 (385e4b4d6cf2) for framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000 (default) at scheduler-4a91827f-30ca-44bd-86b3-8f8005d48abd@172.17.0.4:56621
3: I1020 04:29:46.344992 25335 master.cpp:3810] 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_blZQlU\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: W1020 04:29:46.346336 25335 master.cpp:2348] Dropping DESTROY offer operation from framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000 (default) at scheduler-4a91827f-30ca-44bd-86b3-8f8005d48abd@172.17.0.4:56621: Not authorized to destroy persistent volumes as 'test-principal'
3: I1020 04:29:46.347687 25347 hierarchical.cpp:1163] 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_blZQlU/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk1,id1:path1]:2048, allocated: {}) on agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 from framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000
3: I1020 04:29:46.350345 25339 hierarchical.cpp:1488] Performed allocation for 1 agents in 2.100217ms
3: I1020 04:29:46.350992 25344 master.cpp:7766] Sending 1 offers to framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000 (default) at scheduler-4a91827f-30ca-44bd-86b3-8f8005d48abd@172.17.0.4:56621
3: I1020 04:29:46.351534 25333 sched.cpp:917] Scheduler::resourceOffers took 94461ns
3: I1020 04:29:46.351815 19143 sched.cpp:2005] Asked to stop the driver
3: I1020 04:29:46.351905 25340 sched.cpp:1187] Stopping framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000
3: I1020 04:29:46.352121 19143 sched.cpp:2005] Asked to stop the driver
3: I1020 04:29:46.352125 25338 master.cpp:8447] Processing TEARDOWN call for framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000 (default) at scheduler-4a91827f-30ca-44bd-86b3-8f8005d48abd@172.17.0.4:56621
3: I1020 04:29:46.352149 25338 master.cpp:8459] Removing framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000 (default) at scheduler-4a91827f-30ca-44bd-86b3-8f8005d48abd@172.17.0.4:56621
3: I1020 04:29:46.352162 25338 master.cpp:3299] Deactivating framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000 (default) at scheduler-4a91827f-30ca-44bd-86b3-8f8005d48abd@172.17.0.4:56621
3: I1020 04:29:46.352207 25342 sched.cpp:1187] Stopping framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001
3: I1020 04:29:46.352257 25340 hierarchical.cpp:412] Deactivated framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000
3: I1020 04:29:46.353037 25338 master.cpp:9389] Removing offer d2a32fd3-4264-44b8-a60e-f855d953f4fd-O5
3: I1020 04:29:46.353205 25335 slave.cpp:3211] Asked to shut down framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000 by master@172.17.0.4:56621
3: I1020 04:29:46.353235 25335 slave.cpp:3226] Cannot shut down unknown framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000
3: I1020 04:29:46.353482 25338 master.cpp:8447] Processing TEARDOWN call for framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001 (creator-framework) at scheduler-bef8033b-bc03-45d2-978d-91a044d1ec65@172.17.0.4:56621
3: I1020 04:29:46.353509 25338 master.cpp:8459] Removing framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001 (creator-framework) at scheduler-bef8033b-bc03-45d2-978d-91a044d1ec65@172.17.0.4:56621
3: I1020 04:29:46.353523 25338 master.cpp:3299] Deactivating framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001 (creator-framework) at scheduler-bef8033b-bc03-45d2-978d-91a044d1ec65@172.17.0.4:56621
3: I1020 04:29:46.353678 25337 slave.cpp:3211] Asked to shut down framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001 by master@172.17.0.4:56621
3: I1020 04:29:46.353761 25337 slave.cpp:3226] Cannot shut down unknown framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001
3: I1020 04:29:46.354967 25348 hierarchical.cpp:1163] 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_blZQlU/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_blZQlU/disk1,id1:path1]:2048, allocated: {}) on agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 from framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000
3: I1020 04:29:46.355267 25348 hierarchical.cpp:355] Removed framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0000
3: I1020 04:29:46.355324 25348 hierarchical.cpp:412] Deactivated framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001
3: I1020 04:29:46.355552 25348 hierarchical.cpp:355] Removed framework d2a32fd3-4264-44b8-a60e-f855d953f4fd-0001
3: I1020 04:29:46.355705 19143 slave.cpp:869] Agent terminating
3: I1020 04:29:46.355917 25338 master.cpp:1303] Agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 at slave(831)@172.17.0.4:56621 (385e4b4d6cf2) disconnected
3: I1020 04:29:46.355936 25338 master.cpp:3336] Disconnecting agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 at slave(831)@172.17.0.4:56621 (385e4b4d6cf2)
3: I1020 04:29:46.356021 25338 master.cpp:3355] Deactivating agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 at slave(831)@172.17.0.4:56621 (385e4b4d6cf2)
3: I1020 04:29:46.356155 25345 hierarchical.cpp:690] Agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0 deactivated
3: I1020 04:29:46.360978 19143 master.cpp:1145] Master terminating
3: I1020 04:29:46.362169 25335 hierarchical.cpp:626] Removed agent d2a32fd3-4264-44b8-a60e-f855d953f4fd-S0
3: [       OK ] DiskResource/PersistentVolumeTest.BadACLDropCreateAndDestroy/1 (103 ms)
3: [----------] 34 tests from DiskResource/PersistentVolumeTest (11476 ms total)
3: 
3: [----------] Global test environment tear-down
3: [==========] 1657 tests from 180 test cases ran. (362514 ms total)
3: [  PASSED  ] 1656 tests.
3: [  FAILED  ] 1 test, listed below:
3: [  FAILED  ] SlaveTest.RegisteredAgentReregisterAfterFailover
3: 
3:  1 FAILED TEST
3:   YOU HAVE 21 DISABLED TESTS
3: 
3: I1020 04:29:46.420882 25349 process.cpp:1067] Failed to accept socket: future discarded
3/3 Test #3: MesosTests .......................***Failed  367.08 sec

67% tests passed, 1 tests failed out of 3

Total Test time (real) = 407.45 sec

The following tests FAILED:
	  3 - MesosTests (Failed)
make[3]: Leaving directory `/mesos/build'
make[2]: Leaving directory `/mesos/build'
make[1]: Leaving directory `/mesos/build'
+ docker rmi mesos-1508471150-10736
Untagged: mesos-1508471150-10736:latest
Deleted: sha256:12acf3cccb0b769ab06b7ad7d82129879107d40da7b09d2159b98dbf9089964b
Deleted: sha256:3ef8708943ca8b701a6c07d6e83b6bbd742179351286917474ef35d9cac5e90e
Deleted: sha256:11331b7395c7b617ffcd0de9d6e025767e2efb00ee3724bcb68d6e412192e35a
Deleted: sha256:86e2395211d2583e93e22d9cf788898cd6c307aaae5b704f2ec0dc28315c57f8
Deleted: sha256:7f89ceaef97e7e05a63bf79e776be083cd435914ef0ad18509f0eb43ed5c1a5f
Deleted: sha256:197c6df9f76eccab0f8c0a2ee0d32c3d5f170b8462958a3d695c6b00625e7647
Deleted: sha256:a9b9991c58259434eed15bd27cc5580f48754796b186a97e75329fdf8fac74be
Deleted: sha256:fa235784488e26bb0e4c0eb1be762b5a768df6c2bfb59c27d97da3135b4f4209
Deleted: sha256:9d0c7c359e905eb182e61a762a43cfe4765799d550acf28841a3956f52618357
Deleted: sha256:d59ccb6bb5676e1af390ecbe8cea56cfcd914e31cdbc34653577e42a26406a64
Deleted: sha256:36d6b14c6d527b561f846f3b5b70e793e668a0ffe5d4456ef9ec44ea199e0319
Deleted: sha256:2f83c30665bc8be9af26b7ed6f3a00bdf08f3e2f95d5118b8a7350d26158503d
Deleted: sha256:bee87d898da63db5eb41514eb5f8841b207a03e1f0fdccb7141ebc8d894610d5
Deleted: sha256:9ad7aefe1ae9f20a78694d7d649bbe074467fa89d01bbaf37cce511021b58b8c
Deleted: sha256:6edc1a4db28e4d6b4bc1e4a97b20729cc6cc18d8ae3386121a2f5684bfe947d8
Deleted: sha256:15d17ebe1c8889d35357c00eb72ef6f8498b11c64bdfe93d4722ae8f9f46edca
Deleted: sha256:4bf302ff763a45f8573c164b1c19dd1d06b9c57c53f86476eaacba5e0dd3c6c4
Deleted: sha256:9b0444f2c0afae60f7c24e96d3e49b2706204feaf4dbaf945bd54578adafe295
Deleted: sha256:03555857837c215c067bfc169ba8efe9713b70f62827c99750732a673cec3c7f
Deleted: sha256:604e6adf5134442d0cf7524af28860fd22336fd7107715d34a4537f1adc3ce75
Deleted: sha256:b2d2801aa5a7ad9027fe69a9228dec3fb1d0dec93c037043a99f8a7c98ee1fbe
Deleted: sha256:01f76f7261aafdc3de6ca639056a50ef7a74702968704968d509fbb267aede62
Deleted: sha256:071c7bf67ea14b2050b766e0eb46912925d9d143073d5e78a32de076af732b95
Deleted: sha256:1024aef99d025b72a9bd71975d6e1be6f0f95d4e57c49a7355cf318fefe2cad3
Deleted: sha256:a161ccc21a5f9232c0e54d1cfdd859a4c2d595fc929e0dd21a63d92397f60a67
Deleted: sha256:ca9f1239b17f9fd739d08fe9e9af3513487dfc24461bf4e97aea0887d9845f00
Deleted: sha256:bf449064b67120b53e5f2b8d381f093d26e1e80694b9fc28cfa7c69e8a6b5c11
Deleted: sha256:4db6cf2676ad3d41dd8fb1e968007b6ce00d2c32b4d8850b015e84c253b14f41
Build step 'Execute shell' marked build as failure