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/12 07:51:59 UTC

Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers,GLOG_v=1 MESOS_VERBOSE=1,centos:7,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4312

See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4312/display/redirect>

------------------------------------------
[...truncated 29.79 MB...]
3: I1012 07:51:41.103389 15889 registrar.cpp:347] Recovering registrar
3: I1012 07:51:41.103911 15889 registrar.cpp:391] Successfully fetched the registry (0B) in 0ns
3: I1012 07:51:41.104002 15889 registrar.cpp:495] Applied 1 operations in 25363ns; attempting to update the registry
3: I1012 07:51:41.104501 15889 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1012 07:51:41.104625 15889 registrar.cpp:424] Successfully recovered registrar
3: I1012 07:51:41.104961 15888 master.cpp:1791] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1012 07:51:41.104975 15905 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: W1012 07:51:41.110060 15882 process.cpp:3194] Attempted to spawn already running process files@172.17.0.4:42854
3: I1012 07:51:41.110930 15882 containerizer.cpp:292] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1012 07:51:41.111439 15882 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1012 07:51:41.111553 15882 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1012 07:51:41.111582 15882 provisioner.cpp:255] Using default backend 'copy'
3: I1012 07:51:41.113387 15882 cluster.cpp:448] Creating default 'local' authorizer
3: I1012 07:51:41.115440 15905 slave.cpp:254] Mesos agent started on (821)@172.17.0.4:42854
3: I1012 07:51:41.115461 15905 slave.cpp:255] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_row3PU/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_row3PU/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_row3PU/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_row3PU/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_row3PU/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_hLpLMR\/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_hLpLMR\/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_row3PU" --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_zY1ojT" --zk_session_timeout="10secs"
3: I1012 07:51:41.115816 15905 credentials.hpp:86] Loading credential for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_row3PU/credential'
3: W1012 07:51:41.115921 15882 process.cpp:3194] Attempted to spawn already running process version@172.17.0.4:42854
3: I1012 07:51:41.115963 15905 slave.cpp:287] Agent using credential for: test-principal
3: I1012 07:51:41.115981 15905 credentials.hpp:37] Loading credentials for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_row3PU/http_credentials'
3: I1012 07:51:41.116200 15905 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1012 07:51:41.116384 15905 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1012 07:51:41.116809 15882 sched.cpp:232] Version: 1.5.0
3: I1012 07:51:41.117272 15890 sched.cpp:336] New master detected at master@172.17.0.4:42854
3: I1012 07:51:41.117364 15890 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1012 07:51:41.117378 15890 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.4:42854
3: I1012 07:51:41.117473 15890 sched.cpp:853] Will retry registration in 1.593911759secs if necessary
3: I1012 07:51:41.117661 15897 master.cpp:2929] Received SUBSCRIBE call for framework 'default' at scheduler-825e4b83-4938-4cfd-a9c6-6bbbb86e471c@172.17.0.4:42854
3: I1012 07:51:41.117779 15897 master.cpp:2263] Authorizing framework principal 'test-principal' to receive offers for roles '{ default-role }'
3: I1012 07:51:41.118201 15894 master.cpp:3009] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1012 07:51:41.118679 15886 sched.cpp:747] Framework registered with f4e249be-54e5-48d4-8415-219640207884-0000
3: I1012 07:51:41.118719 15886 sched.cpp:761] Scheduler::registered took 20592ns
3: I1012 07:51:41.118831 15902 hierarchical.cpp:303] Added framework f4e249be-54e5-48d4-8415-219640207884-0000
3: I1012 07:51:41.119007 15902 hierarchical.cpp:1943] No allocations performed
3: I1012 07:51:41.119046 15902 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 07:51:41.119083 15902 hierarchical.cpp:1486] Performed allocation for 0 agents in 118207ns
3: I1012 07:51:41.120082 15905 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_hLpLMR\/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_hLpLMR\/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: I1012 07:51:41.120525 15905 slave.cpp:593] Agent attributes: [  ]
3: I1012 07:51:41.120537 15905 slave.cpp:602] Agent hostname: a4e62d4fd8af
3: I1012 07:51:41.120666 15889 status_update_manager.cpp:177] Pausing sending status updates
3: I1012 07:51:41.122227 15892 state.cpp:64] Recovering state from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_zY1ojT/meta'
3: I1012 07:51:41.122493 15883 status_update_manager.cpp:203] Recovering status update manager
3: I1012 07:51:41.122669 15901 containerizer.cpp:648] Recovering containerizer
3: I1012 07:51:41.123935 15886 provisioner.cpp:416] Provisioner recovery complete
3: I1012 07:51:41.124227 15889 slave.cpp:6310] Finished recovery
3: I1012 07:51:41.124640 15889 slave.cpp:6492] Querying resource estimator for oversubscribable resources
3: I1012 07:51:41.124891 15887 status_update_manager.cpp:177] Pausing sending status updates
3: I1012 07:51:41.124904 15889 slave.cpp:993] New master detected at master@172.17.0.4:42854
3: I1012 07:51:41.124951 15889 slave.cpp:1028] Detecting new master
3: I1012 07:51:41.125074 15889 slave.cpp:6506] Received oversubscribable resources {} from the resource estimator
3: I1012 07:51:41.126478 15896 slave.cpp:1055] Authenticating with master master@172.17.0.4:42854
3: I1012 07:51:41.126533 15896 slave.cpp:1064] Using default CRAM-MD5 authenticatee
3: I1012 07:51:41.126751 15883 authenticatee.cpp:121] Creating new client SASL connection
3: I1012 07:51:41.126835 15903 hierarchical.cpp:1943] No allocations performed
3: I1012 07:51:41.126863 15903 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 07:51:41.126950 15903 hierarchical.cpp:1486] Performed allocation for 0 agents in 143765ns
3: I1012 07:51:41.127050 15898 master.cpp:7936] Authenticating slave(821)@172.17.0.4:42854
3: I1012 07:51:41.127172 15897 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1484)@172.17.0.4:42854
3: I1012 07:51:41.127396 15890 authenticator.cpp:98] Creating new server SASL connection
3: I1012 07:51:41.127583 15891 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1012 07:51:41.127604 15891 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1012 07:51:41.127732 15895 authenticator.cpp:204] Received SASL authentication start
3: I1012 07:51:41.127787 15895 authenticator.cpp:326] Authentication requires more steps
3: I1012 07:51:41.127887 15904 authenticatee.cpp:259] Received SASL authentication step
3: I1012 07:51:41.128006 15901 authenticator.cpp:232] Received SASL authentication step
3: I1012 07:51:41.128043 15901 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'a4e62d4fd8af' server FQDN: 'a4e62d4fd8af' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1012 07:51:41.128058 15901 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1012 07:51:41.128098 15901 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1012 07:51:41.128123 15901 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'a4e62d4fd8af' server FQDN: 'a4e62d4fd8af' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1012 07:51:41.128132 15901 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1012 07:51:41.128139 15901 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1012 07:51:41.128154 15901 authenticator.cpp:318] Authentication success
3: I1012 07:51:41.128233 15888 authenticatee.cpp:299] Authentication success
3: I1012 07:51:41.128314 15894 master.cpp:7966] Successfully authenticated principal 'test-principal' at slave(821)@172.17.0.4:42854
3: I1012 07:51:41.128347 15884 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1484)@172.17.0.4:42854
3: I1012 07:51:41.128545 15885 slave.cpp:1147] Successfully authenticated with master master@172.17.0.4:42854
3: I1012 07:51:41.128777 15885 slave.cpp:1626] Will retry registration in 8.434174ms if necessary
3: I1012 07:51:41.128949 15900 master.cpp:5801] Received register agent message from slave(821)@172.17.0.4:42854 (a4e62d4fd8af)
3: I1012 07:51:41.129073 15900 master.cpp:3838] Authorizing agent with principal 'test-principal'
3: I1012 07:51:41.129436 15905 master.cpp:5861] Authorized registration of agent at slave(821)@172.17.0.4:42854 (a4e62d4fd8af)
3: I1012 07:51:41.129551 15905 master.cpp:5954] Registering agent at slave(821)@172.17.0.4:42854 (a4e62d4fd8af) with id f4e249be-54e5-48d4-8415-219640207884-S0
3: I1012 07:51:41.129967 15889 registrar.cpp:495] Applied 1 operations in 60456ns; attempting to update the registry
3: I1012 07:51:41.130484 15889 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1012 07:51:41.130681 15903 master.cpp:6001] Admitted agent f4e249be-54e5-48d4-8415-219640207884-S0 at slave(821)@172.17.0.4:42854 (a4e62d4fd8af)
3: I1012 07:51:41.131326 15897 slave.cpp:4966] Received ping from slave-observer(739)@172.17.0.4:42854
3: I1012 07:51:41.131515 15895 slave.cpp:1193] Registered with master master@172.17.0.4:42854; given agent ID f4e249be-54e5-48d4-8415-219640207884-S0
3: I1012 07:51:41.131608 15904 status_update_manager.cpp:184] Resuming sending status updates
3: I1012 07:51:41.131790 15895 slave.cpp:1213] Checkpointing SlaveInfo to '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_zY1ojT/meta/slaves/f4e249be-54e5-48d4-8415-219640207884-S0/slave.info'
3: I1012 07:51:41.131459 15903 master.cpp:6032] Registered agent f4e249be-54e5-48d4-8415-219640207884-S0 at slave(821)@172.17.0.4:42854 (a4e62d4fd8af) 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_hLpLMR\/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_hLpLMR\/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: I1012 07:51:41.132146 15895 slave.cpp:1262] Forwarding total oversubscribed resources {}
3: I1012 07:51:41.132308 15888 master.cpp:6817] Received update of agent f4e249be-54e5-48d4-8415-219640207884-S0 at slave(821)@172.17.0.4:42854 (a4e62d4fd8af) with total oversubscribed resources {}
3: I1012 07:51:41.132313 15890 hierarchical.cpp:593] Added agent f4e249be-54e5-48d4-8415-219640207884-S0 (a4e62d4fd8af) with cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk2]:2048; ports:[31000-32000] (allocated: {})
3: I1012 07:51:41.132560 15888 master.cpp:6828] Ignoring update on agent f4e249be-54e5-48d4-8415-219640207884-S0 at slave(821)@172.17.0.4:42854 (a4e62d4fd8af) as it reports no changes
3: I1012 07:51:41.134001 15890 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 07:51:41.134038 15890 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.568788ms
3: I1012 07:51:41.134807 15901 master.cpp:7766] Sending 1 offers to framework f4e249be-54e5-48d4-8415-219640207884-0000 (default) at scheduler-825e4b83-4938-4cfd-a9c6-6bbbb86e471c@172.17.0.4:42854
3: I1012 07:51:41.135339 15886 sched.cpp:917] Scheduler::resourceOffers took 119728ns
3: I1012 07:51:41.137037 15894 master.cpp:9389] Removing offer f4e249be-54e5-48d4-8415-219640207884-O0
3: I1012 07:51:41.137174 15894 master.cpp:4196] Processing ACCEPT call for offers: [ f4e249be-54e5-48d4-8415-219640207884-O0 ] on agent f4e249be-54e5-48d4-8415-219640207884-S0 at slave(821)@172.17.0.4:42854 (a4e62d4fd8af) for framework f4e249be-54e5-48d4-8415-219640207884-0000 (default) at scheduler-825e4b83-4938-4cfd-a9c6-6bbbb86e471c@172.17.0.4:42854
3: I1012 07:51:41.137320 15894 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_hLpLMR\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: W1012 07:51:41.138299 15894 master.cpp:2348] Dropping CREATE offer operation from framework f4e249be-54e5-48d4-8415-219640207884-0000 (default) at scheduler-825e4b83-4938-4cfd-a9c6-6bbbb86e471c@172.17.0.4:42854: Not authorized to create persistent volumes as 'test-principal'
3: I1012 07:51:41.139706 15887 hierarchical.cpp:1161] 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_hLpLMR/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk2]:2048; ports:[31000-32000], allocated: {}) on agent f4e249be-54e5-48d4-8415-219640207884-S0 from framework f4e249be-54e5-48d4-8415-219640207884-0000
3: I1012 07:51:41.142751 15892 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 07:51:41.142797 15892 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.493486ms
3: I1012 07:51:41.143498 15896 master.cpp:7766] Sending 1 offers to framework f4e249be-54e5-48d4-8415-219640207884-0000 (default) at scheduler-825e4b83-4938-4cfd-a9c6-6bbbb86e471c@172.17.0.4:42854
3: I1012 07:51:41.144026 15883 sched.cpp:917] Scheduler::resourceOffers took 99253ns
3: W1012 07:51:41.144695 15882 process.cpp:3194] Attempted to spawn already running process version@172.17.0.4:42854
3: I1012 07:51:41.144706 15898 master.cpp:5207] Processing DECLINE call for offers: [ f4e249be-54e5-48d4-8415-219640207884-O1 ] for framework f4e249be-54e5-48d4-8415-219640207884-0000 (default) at scheduler-825e4b83-4938-4cfd-a9c6-6bbbb86e471c@172.17.0.4:42854
3: I1012 07:51:41.145375 15882 sched.cpp:232] Version: 1.5.0
3: I1012 07:51:41.145824 15888 sched.cpp:336] New master detected at master@172.17.0.4:42854
3: I1012 07:51:41.145910 15888 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1012 07:51:41.145925 15888 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.4:42854
3: I1012 07:51:41.145943 15898 master.cpp:9389] Removing offer f4e249be-54e5-48d4-8415-219640207884-O1
3: I1012 07:51:41.146035 15888 sched.cpp:853] Will retry registration in 248.411145ms if necessary
3: I1012 07:51:41.146131 15898 master.cpp:3439] Processing SUPPRESS call for framework f4e249be-54e5-48d4-8415-219640207884-0000 (default) at scheduler-825e4b83-4938-4cfd-a9c6-6bbbb86e471c@172.17.0.4:42854
3: I1012 07:51:41.146359 15898 master.cpp:2929] Received SUBSCRIBE call for framework 'creator-framework' at scheduler-e4ca603b-e40a-4bf3-9dcd-53e593c05341@172.17.0.4:42854
3: I1012 07:51:41.146445 15898 master.cpp:2263] Authorizing framework principal 'creator-principal' to receive offers for roles '{ default-role }'
3: I1012 07:51:41.146834 15886 master.cpp:3009] Subscribing framework creator-framework with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1012 07:51:41.146930 15891 hierarchical.cpp:1161] 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_hLpLMR/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk2]:2048; ports:[31000-32000], allocated: {}) on agent f4e249be-54e5-48d4-8415-219640207884-S0 from framework f4e249be-54e5-48d4-8415-219640207884-0000
3: I1012 07:51:41.147095 15891 hierarchical.cpp:1273] Suppressed offers for roles { default-role } of framework f4e249be-54e5-48d4-8415-219640207884-0000
3: I1012 07:51:41.147289 15902 sched.cpp:747] Framework registered with f4e249be-54e5-48d4-8415-219640207884-0001
3: I1012 07:51:41.147308 15891 hierarchical.cpp:303] Added framework f4e249be-54e5-48d4-8415-219640207884-0001
3: I1012 07:51:41.147325 15902 sched.cpp:761] Scheduler::registered took 17096ns
3: I1012 07:51:41.148919 15891 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 07:51:41.148957 15891 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.537294ms
3: I1012 07:51:41.149726 15899 master.cpp:7766] Sending 1 offers to framework f4e249be-54e5-48d4-8415-219640207884-0001 (creator-framework) at scheduler-e4ca603b-e40a-4bf3-9dcd-53e593c05341@172.17.0.4:42854
3: I1012 07:51:41.150216 15885 sched.cpp:917] Scheduler::resourceOffers took 96407ns
3: I1012 07:51:41.151832 15900 hierarchical.cpp:1943] No allocations performed
3: I1012 07:51:41.151873 15900 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 07:51:41.151906 15900 hierarchical.cpp:1486] Performed allocation for 1 agents in 164201ns
3: I1012 07:51:41.153623 15905 master.cpp:9389] Removing offer f4e249be-54e5-48d4-8415-219640207884-O2
3: I1012 07:51:41.153740 15905 master.cpp:4196] Processing ACCEPT call for offers: [ f4e249be-54e5-48d4-8415-219640207884-O2 ] on agent f4e249be-54e5-48d4-8415-219640207884-S0 at slave(821)@172.17.0.4:42854 (a4e62d4fd8af) for framework f4e249be-54e5-48d4-8415-219640207884-0001 (creator-framework) at scheduler-e4ca603b-e40a-4bf3-9dcd-53e593c05341@172.17.0.4:42854
3: I1012 07:51:41.153882 15905 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_hLpLMR\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: I1012 07:51:41.155349 15905 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_hLpLMR\/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 f4e249be-54e5-48d4-8415-219640207884-0001 (creator-framework) at scheduler-e4ca603b-e40a-4bf3-9dcd-53e593c05341@172.17.0.4:42854 to agent f4e249be-54e5-48d4-8415-219640207884-S0 at slave(821)@172.17.0.4:42854 (a4e62d4fd8af)
3: I1012 07:51:41.155963 15905 master.cpp:9335] Sending updated checkpointed resources disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk1,id1:path1]:2048 to agent f4e249be-54e5-48d4-8415-219640207884-S0 at slave(821)@172.17.0.4:42854 (a4e62d4fd8af)
3: I1012 07:51:41.157176 15897 slave.cpp:3519] Updated checkpointed resources from {} to disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk1,id1:path1]:2048
3: I1012 07:51:41.159885 15904 hierarchical.cpp:887] Updated allocation of framework f4e249be-54e5-48d4-8415-219640207884-0001 on agent f4e249be-54e5-48d4-8415-219640207884-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_hLpLMR/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/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_hLpLMR/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk1,id1:path1]:2048
3: I1012 07:51:41.161466 15904 hierarchical.cpp:1161] 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_hLpLMR/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk1,id1:path1]:2048, allocated: {}) on agent f4e249be-54e5-48d4-8415-219640207884-S0 from framework f4e249be-54e5-48d4-8415-219640207884-0001
3: I1012 07:51:41.164505 15903 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 07:51:41.164549 15903 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.532445ms
3: I1012 07:51:41.165283 15890 master.cpp:7766] Sending 1 offers to framework f4e249be-54e5-48d4-8415-219640207884-0001 (creator-framework) at scheduler-e4ca603b-e40a-4bf3-9dcd-53e593c05341@172.17.0.4:42854
3: I1012 07:51:41.165868 15888 sched.cpp:917] Scheduler::resourceOffers took 107017ns
3: I1012 07:51:41.166568 15901 master.cpp:5207] Processing DECLINE call for offers: [ f4e249be-54e5-48d4-8415-219640207884-O3 ] for framework f4e249be-54e5-48d4-8415-219640207884-0001 (creator-framework) at scheduler-e4ca603b-e40a-4bf3-9dcd-53e593c05341@172.17.0.4:42854
3: I1012 07:51:41.167539 15901 master.cpp:9389] Removing offer f4e249be-54e5-48d4-8415-219640207884-O3
3: I1012 07:51:41.167690 15901 master.cpp:3439] Processing SUPPRESS call for framework f4e249be-54e5-48d4-8415-219640207884-0001 (creator-framework) at scheduler-e4ca603b-e40a-4bf3-9dcd-53e593c05341@172.17.0.4:42854
3: I1012 07:51:41.168308 15886 hierarchical.cpp:1161] 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_hLpLMR/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk1,id1:path1]:2048, allocated: {}) on agent f4e249be-54e5-48d4-8415-219640207884-S0 from framework f4e249be-54e5-48d4-8415-219640207884-0001
3: I1012 07:51:41.168473 15886 hierarchical.cpp:1273] Suppressed offers for roles { default-role } of framework f4e249be-54e5-48d4-8415-219640207884-0001
3: I1012 07:51:41.168789 15906 master.cpp:5312] Processing REVIVE call for framework f4e249be-54e5-48d4-8415-219640207884-0000 (default) at scheduler-825e4b83-4938-4cfd-a9c6-6bbbb86e471c@172.17.0.4:42854
3: I1012 07:51:41.168928 15891 hierarchical.cpp:1308] Revived offers for roles { default-role } of framework f4e249be-54e5-48d4-8415-219640207884-0000
3: I1012 07:51:41.170567 15891 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 07:51:41.170606 15891 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.572465ms
3: I1012 07:51:41.171329 15899 master.cpp:7766] Sending 1 offers to framework f4e249be-54e5-48d4-8415-219640207884-0000 (default) at scheduler-825e4b83-4938-4cfd-a9c6-6bbbb86e471c@172.17.0.4:42854
3: I1012 07:51:41.171849 15885 sched.cpp:917] Scheduler::resourceOffers took 105037ns
3: I1012 07:51:41.173478 15884 master.cpp:9389] Removing offer f4e249be-54e5-48d4-8415-219640207884-O4
3: I1012 07:51:41.173604 15884 master.cpp:4196] Processing ACCEPT call for offers: [ f4e249be-54e5-48d4-8415-219640207884-O4 ] on agent f4e249be-54e5-48d4-8415-219640207884-S0 at slave(821)@172.17.0.4:42854 (a4e62d4fd8af) for framework f4e249be-54e5-48d4-8415-219640207884-0000 (default) at scheduler-825e4b83-4938-4cfd-a9c6-6bbbb86e471c@172.17.0.4:42854
3: I1012 07:51:41.173739 15884 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_hLpLMR\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: W1012 07:51:41.174691 15884 master.cpp:2348] Dropping DESTROY offer operation from framework f4e249be-54e5-48d4-8415-219640207884-0000 (default) at scheduler-825e4b83-4938-4cfd-a9c6-6bbbb86e471c@172.17.0.4:42854: Not authorized to destroy persistent volumes as 'test-principal'
3: I1012 07:51:41.176249 15883 hierarchical.cpp:1161] 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_hLpLMR/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk1,id1:path1]:2048, allocated: {}) on agent f4e249be-54e5-48d4-8415-219640207884-S0 from framework f4e249be-54e5-48d4-8415-219640207884-0000
3: I1012 07:51:41.179373 15905 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 07:51:41.179417 15905 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.535287ms
3: I1012 07:51:41.180212 15897 master.cpp:7766] Sending 1 offers to framework f4e249be-54e5-48d4-8415-219640207884-0000 (default) at scheduler-825e4b83-4938-4cfd-a9c6-6bbbb86e471c@172.17.0.4:42854
3: I1012 07:51:41.180734 15904 sched.cpp:917] Scheduler::resourceOffers took 101475ns
3: I1012 07:51:41.181080 15882 sched.cpp:2005] Asked to stop the driver
3: I1012 07:51:41.181193 15895 sched.cpp:1187] Stopping framework f4e249be-54e5-48d4-8415-219640207884-0000
3: I1012 07:51:41.181419 15903 master.cpp:8447] Processing TEARDOWN call for framework f4e249be-54e5-48d4-8415-219640207884-0000 (default) at scheduler-825e4b83-4938-4cfd-a9c6-6bbbb86e471c@172.17.0.4:42854
3: I1012 07:51:41.181445 15882 sched.cpp:2005] Asked to stop the driver
3: I1012 07:51:41.181448 15903 master.cpp:8459] Removing framework f4e249be-54e5-48d4-8415-219640207884-0000 (default) at scheduler-825e4b83-4938-4cfd-a9c6-6bbbb86e471c@172.17.0.4:42854
3: I1012 07:51:41.181469 15903 master.cpp:3299] Deactivating framework f4e249be-54e5-48d4-8415-219640207884-0000 (default) at scheduler-825e4b83-4938-4cfd-a9c6-6bbbb86e471c@172.17.0.4:42854
3: I1012 07:51:41.181515 15895 sched.cpp:1187] Stopping framework f4e249be-54e5-48d4-8415-219640207884-0001
3: I1012 07:51:41.181607 15901 hierarchical.cpp:412] Deactivated framework f4e249be-54e5-48d4-8415-219640207884-0000
3: I1012 07:51:41.182446 15903 master.cpp:9389] Removing offer f4e249be-54e5-48d4-8415-219640207884-O5
3: I1012 07:51:41.182605 15887 slave.cpp:3211] Asked to shut down framework f4e249be-54e5-48d4-8415-219640207884-0000 by master@172.17.0.4:42854
3: I1012 07:51:41.182642 15887 slave.cpp:3226] Cannot shut down unknown framework f4e249be-54e5-48d4-8415-219640207884-0000
3: I1012 07:51:41.182904 15903 master.cpp:8447] Processing TEARDOWN call for framework f4e249be-54e5-48d4-8415-219640207884-0001 (creator-framework) at scheduler-e4ca603b-e40a-4bf3-9dcd-53e593c05341@172.17.0.4:42854
3: I1012 07:51:41.182929 15903 master.cpp:8459] Removing framework f4e249be-54e5-48d4-8415-219640207884-0001 (creator-framework) at scheduler-e4ca603b-e40a-4bf3-9dcd-53e593c05341@172.17.0.4:42854
3: I1012 07:51:41.182948 15903 master.cpp:3299] Deactivating framework f4e249be-54e5-48d4-8415-219640207884-0001 (creator-framework) at scheduler-e4ca603b-e40a-4bf3-9dcd-53e593c05341@172.17.0.4:42854
3: I1012 07:51:41.183137 15905 slave.cpp:3211] Asked to shut down framework f4e249be-54e5-48d4-8415-219640207884-0001 by master@172.17.0.4:42854
3: I1012 07:51:41.183163 15905 slave.cpp:3226] Cannot shut down unknown framework f4e249be-54e5-48d4-8415-219640207884-0001
3: I1012 07:51:41.183207 15886 hierarchical.cpp:1161] 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_hLpLMR/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_hLpLMR/disk1,id1:path1]:2048, allocated: {}) on agent f4e249be-54e5-48d4-8415-219640207884-S0 from framework f4e249be-54e5-48d4-8415-219640207884-0000
3: I1012 07:51:41.183398 15886 hierarchical.cpp:355] Removed framework f4e249be-54e5-48d4-8415-219640207884-0000
3: I1012 07:51:41.183451 15886 hierarchical.cpp:412] Deactivated framework f4e249be-54e5-48d4-8415-219640207884-0001
3: I1012 07:51:41.183640 15886 hierarchical.cpp:355] Removed framework f4e249be-54e5-48d4-8415-219640207884-0001
3: I1012 07:51:41.183833 15882 slave.cpp:869] Agent terminating
3: I1012 07:51:41.183989 15901 master.cpp:1303] Agent f4e249be-54e5-48d4-8415-219640207884-S0 at slave(821)@172.17.0.4:42854 (a4e62d4fd8af) disconnected
3: I1012 07:51:41.184008 15901 master.cpp:3336] Disconnecting agent f4e249be-54e5-48d4-8415-219640207884-S0 at slave(821)@172.17.0.4:42854 (a4e62d4fd8af)
3: I1012 07:51:41.184054 15901 master.cpp:3355] Deactivating agent f4e249be-54e5-48d4-8415-219640207884-S0 at slave(821)@172.17.0.4:42854 (a4e62d4fd8af)
3: I1012 07:51:41.184160 15891 hierarchical.cpp:690] Agent f4e249be-54e5-48d4-8415-219640207884-S0 deactivated
3: I1012 07:51:41.189344 15882 master.cpp:1145] Master terminating
3: I1012 07:51:41.190273 15905 hierarchical.cpp:626] Removed agent f4e249be-54e5-48d4-8415-219640207884-S0
3: [       OK ] DiskResource/PersistentVolumeTest.BadACLDropCreateAndDestroy/1 (101 ms)
3: [----------] 34 tests from DiskResource/PersistentVolumeTest (11488 ms total)
3: 
3: [----------] Global test environment tear-down
3: [==========] 1645 tests from 178 test cases ran. (303550 ms total)
3: [  PASSED  ] 1644 tests.
3: [  FAILED  ] 1 test, listed below:
3: [  FAILED  ] ExamplesTest.TestHTTPFramework
3: 
3:  1 FAILED TEST
3:   YOU HAVE 21 DISABLED TESTS
3: 
3: I1012 07:51:41.260912 15907 process.cpp:1068] Failed to accept socket: future discarded
3/3 Test #3: MesosTests .......................***Failed  308.52 sec

67% tests passed, 1 tests failed out of 3

Total Test time (real) = 318.21 sec

The following tests FAILED:
	  3 - MesosTests (Failed)
Errors while running CTest
make[3]: *** [CMakeFiles/check] Error 8
make[3]: Leaving directory `/mesos/build'
make[2]: *** [CMakeFiles/check.dir/all] Error 2
make[2]: Leaving directory `/mesos/build'
make[1]: *** [CMakeFiles/check.dir/rule] Error 2
make[1]: Leaving directory `/mesos/build'
make: *** [check] Error 2
+ docker rmi mesos-1507792527-27464
Untagged: mesos-1507792527-27464:latest
Deleted: sha256:2267f0871ee9492833f72c771a590f2faa4c41e1321075b7d31035df74468c4f
Deleted: sha256:e81d4d2aa5542affe497f5f6f555e59e06d2de8d45a43fb63453598f83a350dc
Deleted: sha256:907c5489eaa12277a57dc762f793bf69a8df7d6705fee61cdf0cbaebd5e80fb0
Deleted: sha256:9f04faea48ec60972ddf1288cb458d193476cd75fdcec276e1954065c70784dc
Deleted: sha256:90c58728b9c315d405f537d4ef2084fe1fc2bedf49d38d3a819105884148133a
Deleted: sha256:5cc0d0c06777a0a171f31663e696d9ba9660b6d0bf001593dc4a72e93e7e1292
Deleted: sha256:8df7b14de96d854d07b424dddf54f0a5ec191ab2bedea1c542b08c6e42f11010
Deleted: sha256:85d9ca32e21af9241a7b91d0748586652b719392d2a449293788c6342c650a16
Deleted: sha256:c835741bfe28f59182e7a22520e709b02cf9d8f72fc065f0daca5ab69d273aaa
Deleted: sha256:1ca6708130717dd3a3a69d8828e3e9a78ec0977e9fed00131b5ed3c888ce3eae
Deleted: sha256:4b85188510cb66a6cecfecca60fb37fb48653d22dab78f0b9c630e2f69ed2002
Deleted: sha256:96ac9d336652386860d36c7b6abfab65e19762a3df23007c40a97d1bee57ea11
Deleted: sha256:c05465494ab87bd124a16da70def385a11ced4b000c3d986005ab613f1dc346d
Deleted: sha256:e6661c31d438a7407c220a7b4816d5aa90a782bdab77e5dd2f493f3625f40811
Deleted: sha256:83ca914c0f48dea9dc8e4c83f87fd6fa1b522aad34b3f85bfb4f4c45614031a1
Deleted: sha256:b4a9081787fd83a3540659f3e75c2f15babc74fd90d8bdcf59a88d7c1a5353fe
Deleted: sha256:435c66f36ff2548d6d32579b5f03bf813b4f924f4e686cfd0353becfd2ff3c57
Deleted: sha256:a00b46410efe7239d26dffdcb9f40948cd4648e3b1a8850ce0064aebb3e7c15b
Deleted: sha256:40d5579e1f5e2262bd0dbd33293eacf241cbbf892edd86041c7d73b5c38df23f
Deleted: sha256:d7675d18819d2807343c9fedc9a6ccc466087c06b6f97ede97b8024186bd0e18
Deleted: sha256:809eeb6ed7d20fe93d64aefe695f66cbf2c310a3e3edda14535ec1f17db58e02
Deleted: sha256:ab77860b6d0a3b8105af4f0977a9e1ce1db4ee8293695f4bb79dce5beabdfd8a
Deleted: sha256:67834844ee44d6bfcdaf815eb2ccf993156b681e101a4dbb23d59902a28e2123
Deleted: sha256:11cbc610b0c3714eeab521cd5de4fbf29a5e8966be24f28ae04bacda95515cdc
Deleted: sha256:c916b2903e30df97c8c9a079678470be44ebac1c762960563426751907a9a867
Deleted: sha256:bd547794723303096fcfcf269798aa72b1164f46f267e3f1613fa9a632b22823
Deleted: sha256:4e96347234e4b4457e0d73c578fb1528e1f9790c616b7c06db5f2901e4f1a94a
Deleted: sha256:cef7bf23d58cd87fe29b07fa74a991b21a163c536ca2c3217c5ef6d699dc7adf
Deleted: sha256:6ffb75855d49fbbbcd84668b89f1ba9cc0bc6aaf4ec4a62b8d1e1dddeaf519c8
Build step 'Execute shell' marked build as failure


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

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4314/display/redirect?page=changes>


Re: Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers,GLOG_v=1 MESOS_VERBOSE=1,centos:7,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4313

Posted by Alex R <al...@apache.org>.
This is likely because of the TASK_STARTING introduction. Benno, could you
please have a look?

On 12 October 2017 at 09:52, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:

> See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=
> cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers,
> ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_
> exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!
> H23)/4313/display/redirect?page=changes>
>
> Changes:
>
> [alexr] Sent TASK_STARTING from the built-in executors.
>
> [alexr] Fix unit tests that were broken by the additional TASK_STARTING
> update.
>
> [alexr] Added MESOS-7941 to changelog and to upgrade guidelines.
>
> ------------------------------------------
> [...truncated 30.53 MB...]
> 3: I1012 16:52:01.670624 15894 registrar.cpp:347] Recovering registrar
> 3: I1012 16:52:01.671197 15894 registrar.cpp:391] Successfully fetched the
> registry (0B) in 0ns
> 3: I1012 16:52:01.671306 15894 registrar.cpp:495] Applied 1 operations in
> 30486ns; attempting to update the registry
> 3: I1012 16:52:01.671836 15894 registrar.cpp:552] Successfully updated the
> registry in 0ns
> 3: I1012 16:52:01.671941 15894 registrar.cpp:424] Successfully recovered
> registrar
> 3: I1012 16:52:01.672256 15885 master.cpp:1791] Recovered 0 agents from
> the registry (129B); allowing 10mins for agents to re-register
> 3: I1012 16:52:01.672276 15906 hierarchical.cpp:209] Skipping recovery of
> hierarchical allocator: nothing to recover
> 3: W1012 16:52:01.677652 15882 process.cpp:3194] Attempted to spawn
> already running process files@172.17.0.2:41006
> 3: I1012 16:52:01.678486 15882 containerizer.cpp:292] Using isolation {
> environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
> 3: W1012 16:52:01.678951 15882 backend.cpp:76] Failed to create 'aufs'
> backend: AufsBackend requires root privileges
> 3: W1012 16:52:01.679064 15882 backend.cpp:76] Failed to create 'bind'
> backend: BindBackend requires root privileges
> 3: I1012 16:52:01.679095 15882 provisioner.cpp:255] Using default backend
> 'copy'
> 3: I1012 16:52:01.680833 15882 cluster.cpp:448] Creating default 'local'
> authorizer
> 3: I1012 16:52:01.682791 15885 slave.cpp:254] Mesos agent started on (821)@
> 172.17.0.2:41006
> 3: W1012 16:52:01.683257 15882 process.cpp:3194] Attempted to spawn
> already running process version@172.17.0.2:41006
> 3: I1012 16:52:01.682811 15885 slave.cpp:255] Flags at startup: --acls=""
> --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/
> DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XOGO3G/store/appc"
> --authenticate_http_readonly="true" --authenticate_http_readwrite="true"
> --authenticatee="crammd5" --authentication_backoff_factor="1secs"
> --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false"
> --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup"
> --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs"
> --containerizers="mesos" --credential="/tmp/DiskResource_
> PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XOGO3G/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_XOGO3G/store/docker"
> --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume"
> --enforce_container_disk_quota="false" --executor_registration_timeout="1mins"
> --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs"
> --fetcher_cache_dir="/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_XOGO3G/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_XOGO3G/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_
> jP4miS\/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_jP4miS\/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_XOGO3G"
> --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_iPd5Fh" --zk_session_timeout="10secs"
> 3: I1012 16:52:01.683387 15885 credentials.hpp:86] Loading credential for
> authentication from '/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_XOGO3G/credential'
> 3: I1012 16:52:01.683548 15885 slave.cpp:287] Agent using credential for:
> test-principal
> 3: I1012 16:52:01.683564 15885 credentials.hpp:37] Loading credentials for
> authentication from '/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_XOGO3G/http_credentials'
> 3: I1012 16:52:01.683786 15885 http.cpp:1045] Creating default 'basic'
> HTTP authenticator for realm 'mesos-agent-readonly'
> 3: I1012 16:52:01.683959 15885 http.cpp:1045] Creating default 'basic'
> HTTP authenticator for realm 'mesos-agent-readwrite'
> 3: I1012 16:52:01.684123 15882 sched.cpp:232] Version: 1.5.0
> 3: I1012 16:52:01.684762 15891 sched.cpp:336] New master detected at
> master@172.17.0.2:41006
> 3: I1012 16:52:01.684890 15891 sched.cpp:351] No credentials provided.
> Attempting to register without authentication
> 3: I1012 16:52:01.684906 15891 sched.cpp:820] Sending SUBSCRIBE call to
> master@172.17.0.2:41006
> 3: I1012 16:52:01.685024 15891 sched.cpp:853] Will retry registration in
> 1.593911759secs if necessary
> 3: I1012 16:52:01.685274 15898 master.cpp:2929] Received SUBSCRIBE call
> for framework 'default' at scheduler-a615a9d1-1f1a-4cd6-
> bb0e-bcf97fac8edc@172.17.0.2:41006
> 3: I1012 16:52:01.685371 15898 master.cpp:2263] Authorizing framework
> principal 'test-principal' to receive offers for roles '{ default-role }'
> 3: I1012 16:52:01.685856 15900 master.cpp:3009] Subscribing framework
> default with checkpointing disabled and capabilities [
> RESERVATION_REFINEMENT ]
> 3: I1012 16:52:01.686429 15903 sched.cpp:747] Framework registered with
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
> 3: I1012 16:52:01.686472 15903 sched.cpp:761] Scheduler::registered took
> 22218ns
> 3: I1012 16:52:01.686765 15886 hierarchical.cpp:303] Added framework
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
> 3: I1012 16:52:01.686985 15886 hierarchical.cpp:1943] No allocations
> performed
> 3: I1012 16:52:01.687029 15886 hierarchical.cpp:2033] No inverse offers to
> send out!
> 3: I1012 16:52:01.687079 15886 hierarchical.cpp:1486] Performed allocation
> for 0 agents in 148334ns
> 3: I1012 16:52:01.687161 15885 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_jP4miS\/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_
> jP4miS\/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: I1012 16:52:01.687541 15885 slave.cpp:593] Agent attributes: [  ]
> 3: I1012 16:52:01.687551 15885 slave.cpp:602] Agent hostname: cde9e20428e4
> 3: I1012 16:52:01.687676 15894 status_update_manager.cpp:177] Pausing
> sending status updates
> 3: I1012 16:52:01.689242 15890 state.cpp:64] Recovering state from
> '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_
> iPd5Fh/meta'
> 3: I1012 16:52:01.689507 15897 status_update_manager.cpp:203] Recovering
> status update manager
> 3: I1012 16:52:01.689699 15895 containerizer.cpp:648] Recovering
> containerizer
> 3: I1012 16:52:01.691020 15906 provisioner.cpp:416] Provisioner recovery
> complete
> 3: I1012 16:52:01.691468 15894 slave.cpp:6310] Finished recovery
> 3: I1012 16:52:01.691982 15894 slave.cpp:6492] Querying resource estimator
> for oversubscribable resources
> 3: I1012 16:52:01.692225 15893 status_update_manager.cpp:177] Pausing
> sending status updates
> 3: I1012 16:52:01.692236 15894 slave.cpp:993] New master detected at
> master@172.17.0.2:41006
> 3: I1012 16:52:01.692282 15894 slave.cpp:1028] Detecting new master
> 3: I1012 16:52:01.692394 15894 slave.cpp:6506] Received oversubscribable
> resources {} from the resource estimator
> 3: I1012 16:52:01.693809 15905 slave.cpp:1055] Authenticating with master
> master@172.17.0.2:41006
> 3: I1012 16:52:01.693904 15905 slave.cpp:1064] Using default CRAM-MD5
> authenticatee
> 3: I1012 16:52:01.694226 15897 hierarchical.cpp:1943] No allocations
> performed
> 3: I1012 16:52:01.694229 15904 authenticatee.cpp:121] Creating new client
> SASL connection
> 3: I1012 16:52:01.694265 15897 hierarchical.cpp:2033] No inverse offers to
> send out!
> 3: I1012 16:52:01.694296 15897 hierarchical.cpp:1486] Performed allocation
> for 0 agents in 123501ns
> 3: I1012 16:52:01.694519 15887 master.cpp:7936] Authenticating slave(821)@
> 172.17.0.2:41006
> 3: I1012 16:52:01.694650 15892 authenticator.cpp:414] Starting
> authentication session for crammd5-authenticatee(1484)@172.17.0.2:41006
> 3: I1012 16:52:01.694969 15891 authenticator.cpp:98] Creating new server
> SASL connection
> 3: I1012 16:52:01.695225 15883 authenticatee.cpp:213] Received SASL
> authentication mechanisms: CRAM-MD5
> 3: I1012 16:52:01.695251 15883 authenticatee.cpp:239] Attempting to
> authenticate with mechanism 'CRAM-MD5'
> 3: I1012 16:52:01.695459 15898 authenticator.cpp:204] Received SASL
> authentication start
> 3: I1012 16:52:01.695521 15898 authenticator.cpp:326] Authentication
> requires more steps
> 3: I1012 16:52:01.695646 15883 authenticatee.cpp:259] Received SASL
> authentication step
> 3: I1012 16:52:01.695834 15901 authenticator.cpp:232] Received SASL
> authentication step
> 3: I1012 16:52:01.695861 15901 auxprop.cpp:109] Request to lookup
> properties for user: 'test-principal' realm: 'cde9e20428e4' server FQDN:
> 'cde9e20428e4' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> 3: I1012 16:52:01.695873 15901 auxprop.cpp:181] Looking up auxiliary
> property '*userPassword'
> 3: I1012 16:52:01.695927 15901 auxprop.cpp:181] Looking up auxiliary
> property '*cmusaslsecretCRAM-MD5'
> 3: I1012 16:52:01.695946 15901 auxprop.cpp:109] Request to lookup
> properties for user: 'test-principal' realm: 'cde9e20428e4' server FQDN:
> 'cde9e20428e4' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> 3: I1012 16:52:01.695960 15901 auxprop.cpp:131] Skipping auxiliary
> property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> 3: I1012 16:52:01.695968 15901 auxprop.cpp:131] Skipping auxiliary
> property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> 3: I1012 16:52:01.695986 15901 authenticator.cpp:318] Authentication
> success
> 3: I1012 16:52:01.696123 15895 authenticatee.cpp:299] Authentication
> success
> 3: I1012 16:52:01.696243 15901 master.cpp:7966] Successfully authenticated
> principal 'test-principal' at slave(821)@172.17.0.2:41006
> 3: I1012 16:52:01.696332 15896 authenticator.cpp:432] Authentication
> session cleanup for crammd5-authenticatee(1484)@172.17.0.2:41006
> 3: I1012 16:52:01.696522 15895 slave.cpp:1147] Successfully authenticated
> with master master@172.17.0.2:41006
> 3: I1012 16:52:01.696792 15895 slave.cpp:1626] Will retry registration in
> 8.434174ms if necessary
> 3: I1012 16:52:01.696990 15889 master.cpp:5801] Received register agent
> message from slave(821)@172.17.0.2:41006 (cde9e20428e4)
> 3: I1012 16:52:01.697121 15889 master.cpp:3838] Authorizing agent with
> principal 'test-principal'
> 3: I1012 16:52:01.697538 15884 master.cpp:5861] Authorized registration of
> agent at slave(821)@172.17.0.2:41006 (cde9e20428e4)
> 3: I1012 16:52:01.697643 15884 master.cpp:5954] Registering agent at
> slave(821)@172.17.0.2:41006 (cde9e20428e4) with id
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0
> 3: I1012 16:52:01.698070 15894 registrar.cpp:495] Applied 1 operations in
> 66527ns; attempting to update the registry
> 3: I1012 16:52:01.698678 15894 registrar.cpp:552] Successfully updated the
> registry in 0ns
> 3: I1012 16:52:01.698875 15904 master.cpp:6001] Admitted agent
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006
> (cde9e20428e4)
> 3: I1012 16:52:01.699647 15887 slave.cpp:4966] Received ping from
> slave-observer(737)@172.17.0.2:41006
> 3: I1012 16:52:01.699862 15898 slave.cpp:1193] Registered with master
> master@172.17.0.2:41006; given agent ID 2a3ad4a9-aa2b-4ca0-8f64-
> a009ed92b19a-S0
> 3: I1012 16:52:01.699968 15883 status_update_manager.cpp:184] Resuming
> sending status updates
> 3: I1012 16:52:01.700220 15898 slave.cpp:1213] Checkpointing SlaveInfo to
> '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_
> iPd5Fh/meta/slaves/2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0/slave.info'
> 3: I1012 16:52:01.699791 15904 master.cpp:6032] Registered agent
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006
> (cde9e20428e4) 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_jP4miS\/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_
> jP4miS\/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: I1012 16:52:01.700641 15898 slave.cpp:1262] Forwarding total
> oversubscribed resources {}
> 3: I1012 16:52:01.700870 15901 master.cpp:6817] Received update of agent
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006
> (cde9e20428e4) with total oversubscribed resources {}
> 3: I1012 16:52:01.700886 15892 hierarchical.cpp:593] Added agent
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 (cde9e20428e4) with cpus:2;
> mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1]:2048;
> disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_
> PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk2]:2048;
> ports:[31000-32000] (allocated: {})
> 3: I1012 16:52:01.701107 15901 master.cpp:6828] Ignoring update on agent
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006
> (cde9e20428e4) as it reports no changes
> 3: I1012 16:52:01.703976 15892 hierarchical.cpp:2033] No inverse offers to
> send out!
> 3: I1012 16:52:01.704030 15892 hierarchical.cpp:1486] Performed allocation
> for 1 agents in 2.853262ms
> 3: I1012 16:52:01.704772 15888 master.cpp:7766] Sending 1 offers to
> framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at
> scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
> 3: I1012 16:52:01.705377 15900 sched.cpp:917] Scheduler::resourceOffers
> took 109192ns
> 3: I1012 16:52:01.707938 15886 master.cpp:9389] Removing offer
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O0
> 3: I1012 16:52:01.708112 15886 master.cpp:4196] Processing ACCEPT call for
> offers: [ 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O0 ] on agent
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006
> (cde9e20428e4) for framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
> (default) at scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:
> 41006
> 3: I1012 16:52:01.708346 15886 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_
> jP4miS\/disk1"},"type":"PATH"},"volume":{"container_path":"
> path1","mode":"RW"}},"name":"disk","reservations":[{"role":
> "default-role","type":"STATIC"}],"scalar":{"value":2048.0},"
> type":"SCALAR"}]'
> 3: W1012 16:52:01.709915 15886 master.cpp:2348] Dropping CREATE offer
> operation from framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
> (default) at scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:
> 41006: Not authorized to create persistent volumes as 'test-principal'
> 3: I1012 16:52:01.711336 15893 hierarchical.cpp:1161] 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_jP4miS/disk1]:2048;
> disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk2]:2048;
> ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048;
> disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_
> PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1]:2048;
> disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_
> PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk2]:2048;
> ports:[31000-32000], allocated: {}) on agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0
> from framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
> 3: I1012 16:52:01.714406 15890 hierarchical.cpp:2033] No inverse offers to
> send out!
> 3: I1012 16:52:01.714449 15890 hierarchical.cpp:1486] Performed allocation
> for 1 agents in 1.47219ms
> 3: I1012 16:52:01.715114 15899 master.cpp:7766] Sending 1 offers to
> framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at
> scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
> 3: I1012 16:52:01.715637 15905 sched.cpp:917] Scheduler::resourceOffers
> took 102780ns
> 3: I1012 16:52:01.716230 15897 master.cpp:5207] Processing DECLINE call
> for offers: [ 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O1 ] for framework
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at
> scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
> 3: W1012 16:52:01.716329 15882 process.cpp:3194] Attempted to spawn
> already running process version@172.17.0.2:41006
> 3: I1012 16:52:01.717100 15882 sched.cpp:232] Version: 1.5.0
> 3: I1012 16:52:01.717128 15897 master.cpp:9389] Removing offer
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O1
> 3: I1012 16:52:01.717275 15897 master.cpp:3439] Processing SUPPRESS call
> for framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at
> scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
> 3: I1012 16:52:01.717710 15901 sched.cpp:336] New master detected at
> master@172.17.0.2:41006
> 3: I1012 16:52:01.717759 15887 hierarchical.cpp:1161] 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_jP4miS/disk1]:2048;
> disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk2]:2048;
> ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048;
> disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_
> PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1]:2048;
> disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_
> PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk2]:2048;
> ports:[31000-32000], allocated: {}) on agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0
> from framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
> 3: I1012 16:52:01.717852 15901 sched.cpp:351] No credentials provided.
> Attempting to register without authentication
> 3: I1012 16:52:01.717865 15901 sched.cpp:820] Sending SUBSCRIBE call to
> master@172.17.0.2:41006
> 3: I1012 16:52:01.717941 15887 hierarchical.cpp:1273] Suppressed offers
> for roles { default-role } of framework 2a3ad4a9-aa2b-4ca0-8f64-
> a009ed92b19a-0000
> 3: I1012 16:52:01.718014 15901 sched.cpp:853] Will retry registration in
> 248.411145ms if necessary
> 3: I1012 16:52:01.718248 15892 master.cpp:2929] Received SUBSCRIBE call
> for framework 'creator-framework' at scheduler-4a3e3a01-654a-40ce-
> bab6-756fc52ced02@172.17.0.2:41006
> 3: I1012 16:52:01.718351 15892 master.cpp:2263] Authorizing framework
> principal 'creator-principal' to receive offers for roles '{ default-role }'
> 3: I1012 16:52:01.718825 15903 master.cpp:3009] Subscribing framework
> creator-framework with checkpointing disabled and capabilities [
> RESERVATION_REFINEMENT ]
> 3: I1012 16:52:01.719274 15906 hierarchical.cpp:303] Added framework
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
> 3: I1012 16:52:01.719347 15902 sched.cpp:747] Framework registered with
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
> 3: I1012 16:52:01.719386 15902 sched.cpp:761] Scheduler::registered took
> 19674ns
> 3: I1012 16:52:01.720717 15906 hierarchical.cpp:2033] No inverse offers to
> send out!
> 3: I1012 16:52:01.720754 15906 hierarchical.cpp:1486] Performed allocation
> for 1 agents in 1.37524ms
> 3: I1012 16:52:01.721388 15895 master.cpp:7766] Sending 1 offers to
> framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001 (creator-framework)
> at scheduler-4a3e3a01-654a-40ce-bab6-756fc52ced02@172.17.0.2:41006
> 3: I1012 16:52:01.721839 15889 sched.cpp:917] Scheduler::resourceOffers
> took 93493ns
> 3: I1012 16:52:01.723457 15884 hierarchical.cpp:1943] No allocations
> performed
> 3: I1012 16:52:01.723489 15884 hierarchical.cpp:2033] No inverse offers to
> send out!
> 3: I1012 16:52:01.723520 15884 hierarchical.cpp:1486] Performed allocation
> for 1 agents in 145725ns
> 3: I1012 16:52:01.725137 15890 master.cpp:9389] Removing offer
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O2
> 3: I1012 16:52:01.725251 15890 master.cpp:4196] Processing ACCEPT call for
> offers: [ 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O2 ] on agent
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006
> (cde9e20428e4) for framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
> (creator-framework) at scheduler-4a3e3a01-654a-40ce-
> bab6-756fc52ced02@172.17.0.2:41006
> 3: I1012 16:52:01.725411 15890 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_
> jP4miS\/disk1"},"type":"PATH"},"volume":{"container_path":"
> path1","mode":"RW"}},"name":"disk","reservations":[{"role":
> "default-role","type":"STATIC"}],"scalar":{"value":2048.0},"
> type":"SCALAR"}]'
> 3: I1012 16:52:01.726811 15890 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_jP4miS\/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
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001 (creator-framework) at
> scheduler-4a3e3a01-654a-40ce-bab6-756fc52ced02@172.17.0.2:41006 to agent
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006
> (cde9e20428e4)
> 3: I1012 16:52:01.727336 15890 master.cpp:9335] Sending updated
> checkpointed resources disk(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048
> to agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@
> 172.17.0.2:41006 (cde9e20428e4)
> 3: I1012 16:52:01.728600 15897 slave.cpp:3519] Updated checkpointed
> resources from {} to disk(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_
> jP4miS/disk1,id1:path1]:2048
> 3: I1012 16:52:01.732273 15904 hierarchical.cpp:887] Updated allocation of
> framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001 on agent
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-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_jP4miS/disk1]:2048;
> disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/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_jP4miS/disk2]:2048; disk(allocated:
> default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_
> jP4miS/disk1,id1:path1]:2048
> 3: I1012 16:52:01.734249 15904 hierarchical.cpp:1161] 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_jP4miS/disk2]:2048;
> disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048
> (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations:
> [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_jP4miS/disk2]:2048; disk(reservations:
> [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048, allocated: {})
> on agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 from framework
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
> 3: I1012 16:52:01.737200 15887 hierarchical.cpp:2033] No inverse offers to
> send out!
> 3: I1012 16:52:01.737244 15887 hierarchical.cpp:1486] Performed allocation
> for 1 agents in 1.45097ms
> 3: I1012 16:52:01.738198 15901 master.cpp:7766] Sending 1 offers to
> framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001 (creator-framework)
> at scheduler-4a3e3a01-654a-40ce-bab6-756fc52ced02@172.17.0.2:41006
> 3: I1012 16:52:01.738905 15888 sched.cpp:917] Scheduler::resourceOffers
> took 114143ns
> 3: I1012 16:52:01.739655 15900 master.cpp:5207] Processing DECLINE call
> for offers: [ 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O3 ] for framework
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001 (creator-framework) at
> scheduler-4a3e3a01-654a-40ce-bab6-756fc52ced02@172.17.0.2:41006
> 3: I1012 16:52:01.740563 15900 master.cpp:9389] Removing offer
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O3
> 3: I1012 16:52:01.740717 15900 master.cpp:3439] Processing SUPPRESS call
> for framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
> (creator-framework) at scheduler-4a3e3a01-654a-40ce-
> bab6-756fc52ced02@172.17.0.2:41006
> 3: I1012 16:52:01.741236 15896 hierarchical.cpp:1161] 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_jP4miS/disk2]:2048;
> disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048
> (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations:
> [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_jP4miS/disk2]:2048; disk(reservations:
> [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048, allocated: {})
> on agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 from framework
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
> 3: I1012 16:52:01.741400 15896 hierarchical.cpp:1273] Suppressed offers
> for roles { default-role } of framework 2a3ad4a9-aa2b-4ca0-8f64-
> a009ed92b19a-0001
> 3: I1012 16:52:01.741727 15902 master.cpp:5312] Processing REVIVE call for
> framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at
> scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
> 3: I1012 16:52:01.741860 15906 hierarchical.cpp:1308] Revived offers for
> roles { default-role } of framework 2a3ad4a9-aa2b-4ca0-8f64-
> a009ed92b19a-0000
> 3: I1012 16:52:01.743269 15906 hierarchical.cpp:2033] No inverse offers to
> send out!
> 3: I1012 16:52:01.743302 15906 hierarchical.cpp:1486] Performed allocation
> for 1 agents in 1.350415ms
> 3: I1012 16:52:01.744047 15895 master.cpp:7766] Sending 1 offers to
> framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at
> scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
> 3: I1012 16:52:01.744549 15889 sched.cpp:917] Scheduler::resourceOffers
> took 99895ns
> 3: I1012 16:52:01.746520 15886 master.cpp:9389] Removing offer
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O4
> 3: I1012 16:52:01.746693 15886 master.cpp:4196] Processing ACCEPT call for
> offers: [ 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O4 ] on agent
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006
> (cde9e20428e4) for framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
> (default) at scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:
> 41006
> 3: I1012 16:52:01.746914 15886 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_
> jP4miS\/disk1"},"type":"PATH"},"volume":{"container_path":"
> path1","mode":"RW"}},"name":"disk","reservations":[{"role":
> "default-role","type":"STATIC"}],"scalar":{"value":2048.0},"
> type":"SCALAR"}]'
> 3: W1012 16:52:01.748167 15905 master.cpp:2348] Dropping DESTROY offer
> operation from framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
> (default) at scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:
> 41006: Not authorized to destroy persistent volumes as 'test-principal'
> 3: I1012 16:52:01.749639 15883 hierarchical.cpp:1161] 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_jP4miS/disk2]:2048;
> disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048
> (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations:
> [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_jP4miS/disk2]:2048; disk(reservations:
> [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048, allocated: {})
> on agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 from framework
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
> 3: I1012 16:52:01.752583 15897 hierarchical.cpp:2033] No inverse offers to
> send out!
> 3: I1012 16:52:01.752622 15897 hierarchical.cpp:1486] Performed allocation
> for 1 agents in 1.392227ms
> 3: I1012 16:52:01.753530 15904 master.cpp:7766] Sending 1 offers to
> framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at
> scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
> 3: I1012 16:52:01.754025 15898 sched.cpp:917] Scheduler::resourceOffers
> took 99238ns
> 3: I1012 16:52:01.754321 15882 sched.cpp:2005] Asked to stop the driver
> 3: I1012 16:52:01.754422 15887 sched.cpp:1187] Stopping framework
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
> 3: I1012 16:52:01.754655 15901 master.cpp:8447] Processing TEARDOWN call
> for framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at
> scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
> 3: I1012 16:52:01.754680 15901 master.cpp:8459] Removing framework
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at
> scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
> 3: I1012 16:52:01.754691 15901 master.cpp:3299] Deactivating framework
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at
> scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
> 3: I1012 16:52:01.754735 15882 sched.cpp:2005] Asked to stop the driver
> 3: I1012 16:52:01.754837 15888 hierarchical.cpp:412] Deactivated framework
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
> 3: I1012 16:52:01.754853 15896 sched.cpp:1187] Stopping framework
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
> 3: I1012 16:52:01.755565 15901 master.cpp:9389] Removing offer
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O5
> 3: I1012 16:52:01.755764 15893 slave.cpp:3211] Asked to shut down
> framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 by
> master@172.17.0.2:41006
> 3: I1012 16:52:01.755796 15893 slave.cpp:3226] Cannot shut down unknown
> framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
> 3: I1012 16:52:01.756008 15901 master.cpp:8447] Processing TEARDOWN call
> for framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
> (creator-framework) at scheduler-4a3e3a01-654a-40ce-
> bab6-756fc52ced02@172.17.0.2:41006
> 3: I1012 16:52:01.756033 15901 master.cpp:8459] Removing framework
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001 (creator-framework) at
> scheduler-4a3e3a01-654a-40ce-bab6-756fc52ced02@172.17.0.2:41006
> 3: I1012 16:52:01.756043 15901 master.cpp:3299] Deactivating framework
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001 (creator-framework) at
> scheduler-4a3e3a01-654a-40ce-bab6-756fc52ced02@172.17.0.2:41006
> 3: I1012 16:52:01.756181 15891 slave.cpp:3211] Asked to shut down
> framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001 by
> master@172.17.0.2:41006
> 3: I1012 16:52:01.756227 15891 slave.cpp:3226] Cannot shut down unknown
> framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
> 3: I1012 16:52:01.756911 15903 hierarchical.cpp:1161] 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_jP4miS/disk2]:2048;
> disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048
> (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations:
> [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_jP4miS/disk2]:2048; disk(reservations:
> [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048, allocated: {})
> on agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 from framework
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
> 3: I1012 16:52:01.757163 15903 hierarchical.cpp:355] Removed framework
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
> 3: I1012 16:52:01.757221 15903 hierarchical.cpp:412] Deactivated framework
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
> 3: I1012 16:52:01.757457 15903 hierarchical.cpp:355] Removed framework
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
> 3: I1012 16:52:01.757683 15882 slave.cpp:869] Agent terminating
> 3: I1012 16:52:01.757853 15888 master.cpp:1303] Agent
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006
> (cde9e20428e4) disconnected
> 3: I1012 16:52:01.757876 15888 master.cpp:3336] Disconnecting agent
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006
> (cde9e20428e4)
> 3: I1012 16:52:01.757935 15888 master.cpp:3355] Deactivating agent
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006
> (cde9e20428e4)
> 3: I1012 16:52:01.758075 15899 hierarchical.cpp:690] Agent
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 deactivated
> 3: I1012 16:52:01.763267 15882 master.cpp:1145] Master terminating
> 3: I1012 16:52:01.764628 15903 hierarchical.cpp:626] Removed agent
> 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0
> 3: [       OK ] DiskResource/PersistentVolumeTest.BadACLDropCreateAndDestroy/1
> (107 ms)
> 3: [----------] 34 tests from DiskResource/PersistentVolumeTest (10694 ms
> total)
> 3:
> 3: [----------] Global test environment tear-down
> 3: [==========] 1645 tests from 178 test cases ran. (342525 ms total)
> 3: [  PASSED  ] 1644 tests.
> 3: [  FAILED  ] 1 test, listed below:
> 3: [  FAILED  ] SlaveRecoveryTest/0.RemoveNonCheckpointingFramework,
> where TypeParam = mesos::internal::slave::MesosContainerizer
> 3:
> 3:  1 FAILED TEST
> 3:   YOU HAVE 21 DISABLED TESTS
> 3:
> 3: I1012 16:52:01.824267 15907 process.cpp:1068] Failed to accept socket:
> future discarded
> 3/3 Test #3: MesosTests .......................***Failed  346.98 sec
>
> 67% tests passed, 1 tests failed out of 3
>
> Total Test time (real) = 356.28 sec
>
> The following tests FAILED:
>           3 - MesosTests (Failed)
> Errors while running CTest
> make[3]: *** [CMakeFiles/check] Error 8
> make[3]: Leaving directory `/mesos/build'
> make[2]: *** [CMakeFiles/check.dir/all] Error 2
> make[2]: Leaving directory `/mesos/build'
> make[1]: *** [CMakeFiles/check.dir/rule] Error 2
> make[1]: Leaving directory `/mesos/build'
> make: *** [check] Error 2
> + docker rmi mesos-1507825080-9646
> Untagged: mesos-1507825080-9646:latest
> Deleted: sha256:9d6604f55f3691cf895a84279768d6
> f33d49b6faa58d35d84008087c8a913097
> Deleted: sha256:5e84eff4033b825d7d02575e5a7105
> 8c8d3d08d45d43ee1cac7db31e65f902c7
> Deleted: sha256:62e5917716a36e26d6ec1bbf711048
> 1bae3b5f8d3f0574ef3fe6fa89155278ed
> Deleted: sha256:65bfe3fc0c4a499b89117e7cd76bc6
> 35a15314a11af7832a3e340b2a2bfdfdd2
> Deleted: sha256:d60b3a5826e5b58d34002c5dd0dca0
> e31e0df616583d4456a33c01da17d0fd18
> Deleted: sha256:b749ce837219f78b3aba55ff3647e6
> 4ceee38391caa49c65d46693b9604a8fc9
> Deleted: sha256:59dcf202927148b716f6713bba8473
> ecb5f536ef2f0bc804bd69c9493991e74d
> Deleted: sha256:b7576c3ee6827f7dd9beacf13e4138
> b830c7482bd35893f58694b2a7cb34d44e
> Deleted: sha256:18c9f29c12c9ee90ede9c7382260a0
> 18c37a76036d6fc95bbab333c212fef8b6
> Deleted: sha256:8a6dec3af634098ce55d0b5469b552
> 8d46b539a8fdfea29d6cf0111955fdc97c
> Deleted: sha256:56299dffbe4d711f05585fa1131a7b
> 09f2bc1c73590d7c55d2c77ca1cd065ba9
> Deleted: sha256:fadedab51e7c2837b8787ac83df384
> e01cdc5414a68601cf4c079021ccc19ca0
> Deleted: sha256:f9ac24aecd83e3a2f01ab6fe5e98aa
> 5df73e4d1ac9f3e35d559eee30e36d6de1
> Deleted: sha256:129f7689fd6d5146756adee84a7e64
> f5ba5c4e7273bde0a399a5470b8cede58c
> Deleted: sha256:e987566cdebe8b1fc02b64eb9a36e6
> 882d283df1253cfd8346c5ea511e1af234
> Deleted: sha256:07ab5a7e7bc235c066d85dd93d3e1b
> 13021e5233641af3b1c03468be44bb0310
> Deleted: sha256:34f86771e52f034f8c5818c8cccfe5
> 9d04e60d8662b5007dd84824459f123a98
> Deleted: sha256:566eef0ad575d0be8e98e0347f63fe
> 7c27b93394319cca3e1d31299a98306cb2
> Deleted: sha256:5d33a14590baa764306c0be66986b3
> 749b6072c9ef0926da180b79f1ee081ae8
> Deleted: sha256:3a4a6c90852dc3bf8e872103666457
> 707289610ed0077423a90b66cf37269524
> Deleted: sha256:aa70f1907fb078489adf848a52f70a
> bf428c8d6406cbeefd0934a1f65e457041
> Deleted: sha256:4f1f5c1d1c907019bf373460c90d9e
> 2ec617baad840b5cc8a348300619fd3f44
> Deleted: sha256:77ba1fdc5bb4e5f0f25d191cfdf661
> 3b279a5328affa93081a3c3bb97b6def64
> Deleted: sha256:0ce5ad7a0b9567e267f2f4d6dff352
> c07c4c238e2f8aa4ed95a5c575ce6ce188
> Deleted: sha256:31a90b3f188b1dd80a413d4f613afa
> 871dc7c3580fb6f1443377547288e0a904
> Deleted: sha256:5df38afee6fffc1370a0f747ec044a
> cf9348237856afb31562f889c144032d49
> Deleted: sha256:f5472597a9440cee500059768ca8bd
> b6e78d736c0b593e89bcf4a67c3aa890fd
> Deleted: sha256:cbfdc3b7c39bccab4555a658664a46
> d33e96238d1061f474648edf83a08c684c
> Deleted: sha256:e1774d241e84a6f42088fe9b77d464
> e9eca7e342941ff88dcdbba0e012cddc6b
> Build step 'Execute shell' marked build as failure
>

Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers,GLOG_v=1 MESOS_VERBOSE=1,centos:7,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4313

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4313/display/redirect?page=changes>

Changes:

[alexr] Sent TASK_STARTING from the built-in executors.

[alexr] Fix unit tests that were broken by the additional TASK_STARTING update.

[alexr] Added MESOS-7941 to changelog and to upgrade guidelines.

------------------------------------------
[...truncated 30.53 MB...]
3: I1012 16:52:01.670624 15894 registrar.cpp:347] Recovering registrar
3: I1012 16:52:01.671197 15894 registrar.cpp:391] Successfully fetched the registry (0B) in 0ns
3: I1012 16:52:01.671306 15894 registrar.cpp:495] Applied 1 operations in 30486ns; attempting to update the registry
3: I1012 16:52:01.671836 15894 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1012 16:52:01.671941 15894 registrar.cpp:424] Successfully recovered registrar
3: I1012 16:52:01.672256 15885 master.cpp:1791] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1012 16:52:01.672276 15906 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: W1012 16:52:01.677652 15882 process.cpp:3194] Attempted to spawn already running process files@172.17.0.2:41006
3: I1012 16:52:01.678486 15882 containerizer.cpp:292] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1012 16:52:01.678951 15882 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1012 16:52:01.679064 15882 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1012 16:52:01.679095 15882 provisioner.cpp:255] Using default backend 'copy'
3: I1012 16:52:01.680833 15882 cluster.cpp:448] Creating default 'local' authorizer
3: I1012 16:52:01.682791 15885 slave.cpp:254] Mesos agent started on (821)@172.17.0.2:41006
3: W1012 16:52:01.683257 15882 process.cpp:3194] Attempted to spawn already running process version@172.17.0.2:41006
3: I1012 16:52:01.682811 15885 slave.cpp:255] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XOGO3G/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XOGO3G/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_XOGO3G/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XOGO3G/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_XOGO3G/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_jP4miS\/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_jP4miS\/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_XOGO3G" --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_iPd5Fh" --zk_session_timeout="10secs"
3: I1012 16:52:01.683387 15885 credentials.hpp:86] Loading credential for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XOGO3G/credential'
3: I1012 16:52:01.683548 15885 slave.cpp:287] Agent using credential for: test-principal
3: I1012 16:52:01.683564 15885 credentials.hpp:37] Loading credentials for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XOGO3G/http_credentials'
3: I1012 16:52:01.683786 15885 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1012 16:52:01.683959 15885 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1012 16:52:01.684123 15882 sched.cpp:232] Version: 1.5.0
3: I1012 16:52:01.684762 15891 sched.cpp:336] New master detected at master@172.17.0.2:41006
3: I1012 16:52:01.684890 15891 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1012 16:52:01.684906 15891 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.2:41006
3: I1012 16:52:01.685024 15891 sched.cpp:853] Will retry registration in 1.593911759secs if necessary
3: I1012 16:52:01.685274 15898 master.cpp:2929] Received SUBSCRIBE call for framework 'default' at scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
3: I1012 16:52:01.685371 15898 master.cpp:2263] Authorizing framework principal 'test-principal' to receive offers for roles '{ default-role }'
3: I1012 16:52:01.685856 15900 master.cpp:3009] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1012 16:52:01.686429 15903 sched.cpp:747] Framework registered with 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
3: I1012 16:52:01.686472 15903 sched.cpp:761] Scheduler::registered took 22218ns
3: I1012 16:52:01.686765 15886 hierarchical.cpp:303] Added framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
3: I1012 16:52:01.686985 15886 hierarchical.cpp:1943] No allocations performed
3: I1012 16:52:01.687029 15886 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 16:52:01.687079 15886 hierarchical.cpp:1486] Performed allocation for 0 agents in 148334ns
3: I1012 16:52:01.687161 15885 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_jP4miS\/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_jP4miS\/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: I1012 16:52:01.687541 15885 slave.cpp:593] Agent attributes: [  ]
3: I1012 16:52:01.687551 15885 slave.cpp:602] Agent hostname: cde9e20428e4
3: I1012 16:52:01.687676 15894 status_update_manager.cpp:177] Pausing sending status updates
3: I1012 16:52:01.689242 15890 state.cpp:64] Recovering state from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iPd5Fh/meta'
3: I1012 16:52:01.689507 15897 status_update_manager.cpp:203] Recovering status update manager
3: I1012 16:52:01.689699 15895 containerizer.cpp:648] Recovering containerizer
3: I1012 16:52:01.691020 15906 provisioner.cpp:416] Provisioner recovery complete
3: I1012 16:52:01.691468 15894 slave.cpp:6310] Finished recovery
3: I1012 16:52:01.691982 15894 slave.cpp:6492] Querying resource estimator for oversubscribable resources
3: I1012 16:52:01.692225 15893 status_update_manager.cpp:177] Pausing sending status updates
3: I1012 16:52:01.692236 15894 slave.cpp:993] New master detected at master@172.17.0.2:41006
3: I1012 16:52:01.692282 15894 slave.cpp:1028] Detecting new master
3: I1012 16:52:01.692394 15894 slave.cpp:6506] Received oversubscribable resources {} from the resource estimator
3: I1012 16:52:01.693809 15905 slave.cpp:1055] Authenticating with master master@172.17.0.2:41006
3: I1012 16:52:01.693904 15905 slave.cpp:1064] Using default CRAM-MD5 authenticatee
3: I1012 16:52:01.694226 15897 hierarchical.cpp:1943] No allocations performed
3: I1012 16:52:01.694229 15904 authenticatee.cpp:121] Creating new client SASL connection
3: I1012 16:52:01.694265 15897 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 16:52:01.694296 15897 hierarchical.cpp:1486] Performed allocation for 0 agents in 123501ns
3: I1012 16:52:01.694519 15887 master.cpp:7936] Authenticating slave(821)@172.17.0.2:41006
3: I1012 16:52:01.694650 15892 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1484)@172.17.0.2:41006
3: I1012 16:52:01.694969 15891 authenticator.cpp:98] Creating new server SASL connection
3: I1012 16:52:01.695225 15883 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1012 16:52:01.695251 15883 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1012 16:52:01.695459 15898 authenticator.cpp:204] Received SASL authentication start
3: I1012 16:52:01.695521 15898 authenticator.cpp:326] Authentication requires more steps
3: I1012 16:52:01.695646 15883 authenticatee.cpp:259] Received SASL authentication step
3: I1012 16:52:01.695834 15901 authenticator.cpp:232] Received SASL authentication step
3: I1012 16:52:01.695861 15901 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'cde9e20428e4' server FQDN: 'cde9e20428e4' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1012 16:52:01.695873 15901 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1012 16:52:01.695927 15901 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1012 16:52:01.695946 15901 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'cde9e20428e4' server FQDN: 'cde9e20428e4' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1012 16:52:01.695960 15901 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1012 16:52:01.695968 15901 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1012 16:52:01.695986 15901 authenticator.cpp:318] Authentication success
3: I1012 16:52:01.696123 15895 authenticatee.cpp:299] Authentication success
3: I1012 16:52:01.696243 15901 master.cpp:7966] Successfully authenticated principal 'test-principal' at slave(821)@172.17.0.2:41006
3: I1012 16:52:01.696332 15896 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1484)@172.17.0.2:41006
3: I1012 16:52:01.696522 15895 slave.cpp:1147] Successfully authenticated with master master@172.17.0.2:41006
3: I1012 16:52:01.696792 15895 slave.cpp:1626] Will retry registration in 8.434174ms if necessary
3: I1012 16:52:01.696990 15889 master.cpp:5801] Received register agent message from slave(821)@172.17.0.2:41006 (cde9e20428e4)
3: I1012 16:52:01.697121 15889 master.cpp:3838] Authorizing agent with principal 'test-principal'
3: I1012 16:52:01.697538 15884 master.cpp:5861] Authorized registration of agent at slave(821)@172.17.0.2:41006 (cde9e20428e4)
3: I1012 16:52:01.697643 15884 master.cpp:5954] Registering agent at slave(821)@172.17.0.2:41006 (cde9e20428e4) with id 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0
3: I1012 16:52:01.698070 15894 registrar.cpp:495] Applied 1 operations in 66527ns; attempting to update the registry
3: I1012 16:52:01.698678 15894 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1012 16:52:01.698875 15904 master.cpp:6001] Admitted agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006 (cde9e20428e4)
3: I1012 16:52:01.699647 15887 slave.cpp:4966] Received ping from slave-observer(737)@172.17.0.2:41006
3: I1012 16:52:01.699862 15898 slave.cpp:1193] Registered with master master@172.17.0.2:41006; given agent ID 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0
3: I1012 16:52:01.699968 15883 status_update_manager.cpp:184] Resuming sending status updates
3: I1012 16:52:01.700220 15898 slave.cpp:1213] Checkpointing SlaveInfo to '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_iPd5Fh/meta/slaves/2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0/slave.info'
3: I1012 16:52:01.699791 15904 master.cpp:6032] Registered agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006 (cde9e20428e4) 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_jP4miS\/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_jP4miS\/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: I1012 16:52:01.700641 15898 slave.cpp:1262] Forwarding total oversubscribed resources {}
3: I1012 16:52:01.700870 15901 master.cpp:6817] Received update of agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006 (cde9e20428e4) with total oversubscribed resources {}
3: I1012 16:52:01.700886 15892 hierarchical.cpp:593] Added agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 (cde9e20428e4) with cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk2]:2048; ports:[31000-32000] (allocated: {})
3: I1012 16:52:01.701107 15901 master.cpp:6828] Ignoring update on agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006 (cde9e20428e4) as it reports no changes
3: I1012 16:52:01.703976 15892 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 16:52:01.704030 15892 hierarchical.cpp:1486] Performed allocation for 1 agents in 2.853262ms
3: I1012 16:52:01.704772 15888 master.cpp:7766] Sending 1 offers to framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
3: I1012 16:52:01.705377 15900 sched.cpp:917] Scheduler::resourceOffers took 109192ns
3: I1012 16:52:01.707938 15886 master.cpp:9389] Removing offer 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O0
3: I1012 16:52:01.708112 15886 master.cpp:4196] Processing ACCEPT call for offers: [ 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O0 ] on agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006 (cde9e20428e4) for framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
3: I1012 16:52:01.708346 15886 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_jP4miS\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: W1012 16:52:01.709915 15886 master.cpp:2348] Dropping CREATE offer operation from framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006: Not authorized to create persistent volumes as 'test-principal'
3: I1012 16:52:01.711336 15893 hierarchical.cpp:1161] 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_jP4miS/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk2]:2048; ports:[31000-32000], allocated: {}) on agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 from framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
3: I1012 16:52:01.714406 15890 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 16:52:01.714449 15890 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.47219ms
3: I1012 16:52:01.715114 15899 master.cpp:7766] Sending 1 offers to framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
3: I1012 16:52:01.715637 15905 sched.cpp:917] Scheduler::resourceOffers took 102780ns
3: I1012 16:52:01.716230 15897 master.cpp:5207] Processing DECLINE call for offers: [ 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O1 ] for framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
3: W1012 16:52:01.716329 15882 process.cpp:3194] Attempted to spawn already running process version@172.17.0.2:41006
3: I1012 16:52:01.717100 15882 sched.cpp:232] Version: 1.5.0
3: I1012 16:52:01.717128 15897 master.cpp:9389] Removing offer 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O1
3: I1012 16:52:01.717275 15897 master.cpp:3439] Processing SUPPRESS call for framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
3: I1012 16:52:01.717710 15901 sched.cpp:336] New master detected at master@172.17.0.2:41006
3: I1012 16:52:01.717759 15887 hierarchical.cpp:1161] 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_jP4miS/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk2]:2048; ports:[31000-32000], allocated: {}) on agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 from framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
3: I1012 16:52:01.717852 15901 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1012 16:52:01.717865 15901 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.2:41006
3: I1012 16:52:01.717941 15887 hierarchical.cpp:1273] Suppressed offers for roles { default-role } of framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
3: I1012 16:52:01.718014 15901 sched.cpp:853] Will retry registration in 248.411145ms if necessary
3: I1012 16:52:01.718248 15892 master.cpp:2929] Received SUBSCRIBE call for framework 'creator-framework' at scheduler-4a3e3a01-654a-40ce-bab6-756fc52ced02@172.17.0.2:41006
3: I1012 16:52:01.718351 15892 master.cpp:2263] Authorizing framework principal 'creator-principal' to receive offers for roles '{ default-role }'
3: I1012 16:52:01.718825 15903 master.cpp:3009] Subscribing framework creator-framework with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1012 16:52:01.719274 15906 hierarchical.cpp:303] Added framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
3: I1012 16:52:01.719347 15902 sched.cpp:747] Framework registered with 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
3: I1012 16:52:01.719386 15902 sched.cpp:761] Scheduler::registered took 19674ns
3: I1012 16:52:01.720717 15906 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 16:52:01.720754 15906 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.37524ms
3: I1012 16:52:01.721388 15895 master.cpp:7766] Sending 1 offers to framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001 (creator-framework) at scheduler-4a3e3a01-654a-40ce-bab6-756fc52ced02@172.17.0.2:41006
3: I1012 16:52:01.721839 15889 sched.cpp:917] Scheduler::resourceOffers took 93493ns
3: I1012 16:52:01.723457 15884 hierarchical.cpp:1943] No allocations performed
3: I1012 16:52:01.723489 15884 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 16:52:01.723520 15884 hierarchical.cpp:1486] Performed allocation for 1 agents in 145725ns
3: I1012 16:52:01.725137 15890 master.cpp:9389] Removing offer 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O2
3: I1012 16:52:01.725251 15890 master.cpp:4196] Processing ACCEPT call for offers: [ 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O2 ] on agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006 (cde9e20428e4) for framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001 (creator-framework) at scheduler-4a3e3a01-654a-40ce-bab6-756fc52ced02@172.17.0.2:41006
3: I1012 16:52:01.725411 15890 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_jP4miS\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: I1012 16:52:01.726811 15890 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_jP4miS\/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 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001 (creator-framework) at scheduler-4a3e3a01-654a-40ce-bab6-756fc52ced02@172.17.0.2:41006 to agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006 (cde9e20428e4)
3: I1012 16:52:01.727336 15890 master.cpp:9335] Sending updated checkpointed resources disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048 to agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006 (cde9e20428e4)
3: I1012 16:52:01.728600 15897 slave.cpp:3519] Updated checkpointed resources from {} to disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048
3: I1012 16:52:01.732273 15904 hierarchical.cpp:887] Updated allocation of framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001 on agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-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_jP4miS/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/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_jP4miS/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048
3: I1012 16:52:01.734249 15904 hierarchical.cpp:1161] 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_jP4miS/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048, allocated: {}) on agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 from framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
3: I1012 16:52:01.737200 15887 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 16:52:01.737244 15887 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.45097ms
3: I1012 16:52:01.738198 15901 master.cpp:7766] Sending 1 offers to framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001 (creator-framework) at scheduler-4a3e3a01-654a-40ce-bab6-756fc52ced02@172.17.0.2:41006
3: I1012 16:52:01.738905 15888 sched.cpp:917] Scheduler::resourceOffers took 114143ns
3: I1012 16:52:01.739655 15900 master.cpp:5207] Processing DECLINE call for offers: [ 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O3 ] for framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001 (creator-framework) at scheduler-4a3e3a01-654a-40ce-bab6-756fc52ced02@172.17.0.2:41006
3: I1012 16:52:01.740563 15900 master.cpp:9389] Removing offer 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O3
3: I1012 16:52:01.740717 15900 master.cpp:3439] Processing SUPPRESS call for framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001 (creator-framework) at scheduler-4a3e3a01-654a-40ce-bab6-756fc52ced02@172.17.0.2:41006
3: I1012 16:52:01.741236 15896 hierarchical.cpp:1161] 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_jP4miS/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048, allocated: {}) on agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 from framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
3: I1012 16:52:01.741400 15896 hierarchical.cpp:1273] Suppressed offers for roles { default-role } of framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
3: I1012 16:52:01.741727 15902 master.cpp:5312] Processing REVIVE call for framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
3: I1012 16:52:01.741860 15906 hierarchical.cpp:1308] Revived offers for roles { default-role } of framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
3: I1012 16:52:01.743269 15906 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 16:52:01.743302 15906 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.350415ms
3: I1012 16:52:01.744047 15895 master.cpp:7766] Sending 1 offers to framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
3: I1012 16:52:01.744549 15889 sched.cpp:917] Scheduler::resourceOffers took 99895ns
3: I1012 16:52:01.746520 15886 master.cpp:9389] Removing offer 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O4
3: I1012 16:52:01.746693 15886 master.cpp:4196] Processing ACCEPT call for offers: [ 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O4 ] on agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006 (cde9e20428e4) for framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
3: I1012 16:52:01.746914 15886 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_jP4miS\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: W1012 16:52:01.748167 15905 master.cpp:2348] Dropping DESTROY offer operation from framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006: Not authorized to destroy persistent volumes as 'test-principal'
3: I1012 16:52:01.749639 15883 hierarchical.cpp:1161] 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_jP4miS/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048, allocated: {}) on agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 from framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
3: I1012 16:52:01.752583 15897 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 16:52:01.752622 15897 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.392227ms
3: I1012 16:52:01.753530 15904 master.cpp:7766] Sending 1 offers to framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
3: I1012 16:52:01.754025 15898 sched.cpp:917] Scheduler::resourceOffers took 99238ns
3: I1012 16:52:01.754321 15882 sched.cpp:2005] Asked to stop the driver
3: I1012 16:52:01.754422 15887 sched.cpp:1187] Stopping framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
3: I1012 16:52:01.754655 15901 master.cpp:8447] Processing TEARDOWN call for framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
3: I1012 16:52:01.754680 15901 master.cpp:8459] Removing framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
3: I1012 16:52:01.754691 15901 master.cpp:3299] Deactivating framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 (default) at scheduler-a615a9d1-1f1a-4cd6-bb0e-bcf97fac8edc@172.17.0.2:41006
3: I1012 16:52:01.754735 15882 sched.cpp:2005] Asked to stop the driver
3: I1012 16:52:01.754837 15888 hierarchical.cpp:412] Deactivated framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
3: I1012 16:52:01.754853 15896 sched.cpp:1187] Stopping framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
3: I1012 16:52:01.755565 15901 master.cpp:9389] Removing offer 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-O5
3: I1012 16:52:01.755764 15893 slave.cpp:3211] Asked to shut down framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000 by master@172.17.0.2:41006
3: I1012 16:52:01.755796 15893 slave.cpp:3226] Cannot shut down unknown framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
3: I1012 16:52:01.756008 15901 master.cpp:8447] Processing TEARDOWN call for framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001 (creator-framework) at scheduler-4a3e3a01-654a-40ce-bab6-756fc52ced02@172.17.0.2:41006
3: I1012 16:52:01.756033 15901 master.cpp:8459] Removing framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001 (creator-framework) at scheduler-4a3e3a01-654a-40ce-bab6-756fc52ced02@172.17.0.2:41006
3: I1012 16:52:01.756043 15901 master.cpp:3299] Deactivating framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001 (creator-framework) at scheduler-4a3e3a01-654a-40ce-bab6-756fc52ced02@172.17.0.2:41006
3: I1012 16:52:01.756181 15891 slave.cpp:3211] Asked to shut down framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001 by master@172.17.0.2:41006
3: I1012 16:52:01.756227 15891 slave.cpp:3226] Cannot shut down unknown framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
3: I1012 16:52:01.756911 15903 hierarchical.cpp:1161] 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_jP4miS/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_jP4miS/disk1,id1:path1]:2048, allocated: {}) on agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 from framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
3: I1012 16:52:01.757163 15903 hierarchical.cpp:355] Removed framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0000
3: I1012 16:52:01.757221 15903 hierarchical.cpp:412] Deactivated framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
3: I1012 16:52:01.757457 15903 hierarchical.cpp:355] Removed framework 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-0001
3: I1012 16:52:01.757683 15882 slave.cpp:869] Agent terminating
3: I1012 16:52:01.757853 15888 master.cpp:1303] Agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006 (cde9e20428e4) disconnected
3: I1012 16:52:01.757876 15888 master.cpp:3336] Disconnecting agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006 (cde9e20428e4)
3: I1012 16:52:01.757935 15888 master.cpp:3355] Deactivating agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 at slave(821)@172.17.0.2:41006 (cde9e20428e4)
3: I1012 16:52:01.758075 15899 hierarchical.cpp:690] Agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0 deactivated
3: I1012 16:52:01.763267 15882 master.cpp:1145] Master terminating
3: I1012 16:52:01.764628 15903 hierarchical.cpp:626] Removed agent 2a3ad4a9-aa2b-4ca0-8f64-a009ed92b19a-S0
3: [       OK ] DiskResource/PersistentVolumeTest.BadACLDropCreateAndDestroy/1 (107 ms)
3: [----------] 34 tests from DiskResource/PersistentVolumeTest (10694 ms total)
3: 
3: [----------] Global test environment tear-down
3: [==========] 1645 tests from 178 test cases ran. (342525 ms total)
3: [  PASSED  ] 1644 tests.
3: [  FAILED  ] 1 test, listed below:
3: [  FAILED  ] SlaveRecoveryTest/0.RemoveNonCheckpointingFramework, where TypeParam = mesos::internal::slave::MesosContainerizer
3: 
3:  1 FAILED TEST
3:   YOU HAVE 21 DISABLED TESTS
3: 
3: I1012 16:52:01.824267 15907 process.cpp:1068] Failed to accept socket: future discarded
3/3 Test #3: MesosTests .......................***Failed  346.98 sec

67% tests passed, 1 tests failed out of 3

Total Test time (real) = 356.28 sec

The following tests FAILED:
	  3 - MesosTests (Failed)
Errors while running CTest
make[3]: *** [CMakeFiles/check] Error 8
make[3]: Leaving directory `/mesos/build'
make[2]: *** [CMakeFiles/check.dir/all] Error 2
make[2]: Leaving directory `/mesos/build'
make[1]: *** [CMakeFiles/check.dir/rule] Error 2
make[1]: Leaving directory `/mesos/build'
make: *** [check] Error 2
+ docker rmi mesos-1507825080-9646
Untagged: mesos-1507825080-9646:latest
Deleted: sha256:9d6604f55f3691cf895a84279768d6f33d49b6faa58d35d84008087c8a913097
Deleted: sha256:5e84eff4033b825d7d02575e5a71058c8d3d08d45d43ee1cac7db31e65f902c7
Deleted: sha256:62e5917716a36e26d6ec1bbf7110481bae3b5f8d3f0574ef3fe6fa89155278ed
Deleted: sha256:65bfe3fc0c4a499b89117e7cd76bc635a15314a11af7832a3e340b2a2bfdfdd2
Deleted: sha256:d60b3a5826e5b58d34002c5dd0dca0e31e0df616583d4456a33c01da17d0fd18
Deleted: sha256:b749ce837219f78b3aba55ff3647e64ceee38391caa49c65d46693b9604a8fc9
Deleted: sha256:59dcf202927148b716f6713bba8473ecb5f536ef2f0bc804bd69c9493991e74d
Deleted: sha256:b7576c3ee6827f7dd9beacf13e4138b830c7482bd35893f58694b2a7cb34d44e
Deleted: sha256:18c9f29c12c9ee90ede9c7382260a018c37a76036d6fc95bbab333c212fef8b6
Deleted: sha256:8a6dec3af634098ce55d0b5469b5528d46b539a8fdfea29d6cf0111955fdc97c
Deleted: sha256:56299dffbe4d711f05585fa1131a7b09f2bc1c73590d7c55d2c77ca1cd065ba9
Deleted: sha256:fadedab51e7c2837b8787ac83df384e01cdc5414a68601cf4c079021ccc19ca0
Deleted: sha256:f9ac24aecd83e3a2f01ab6fe5e98aa5df73e4d1ac9f3e35d559eee30e36d6de1
Deleted: sha256:129f7689fd6d5146756adee84a7e64f5ba5c4e7273bde0a399a5470b8cede58c
Deleted: sha256:e987566cdebe8b1fc02b64eb9a36e6882d283df1253cfd8346c5ea511e1af234
Deleted: sha256:07ab5a7e7bc235c066d85dd93d3e1b13021e5233641af3b1c03468be44bb0310
Deleted: sha256:34f86771e52f034f8c5818c8cccfe59d04e60d8662b5007dd84824459f123a98
Deleted: sha256:566eef0ad575d0be8e98e0347f63fe7c27b93394319cca3e1d31299a98306cb2
Deleted: sha256:5d33a14590baa764306c0be66986b3749b6072c9ef0926da180b79f1ee081ae8
Deleted: sha256:3a4a6c90852dc3bf8e872103666457707289610ed0077423a90b66cf37269524
Deleted: sha256:aa70f1907fb078489adf848a52f70abf428c8d6406cbeefd0934a1f65e457041
Deleted: sha256:4f1f5c1d1c907019bf373460c90d9e2ec617baad840b5cc8a348300619fd3f44
Deleted: sha256:77ba1fdc5bb4e5f0f25d191cfdf6613b279a5328affa93081a3c3bb97b6def64
Deleted: sha256:0ce5ad7a0b9567e267f2f4d6dff352c07c4c238e2f8aa4ed95a5c575ce6ce188
Deleted: sha256:31a90b3f188b1dd80a413d4f613afa871dc7c3580fb6f1443377547288e0a904
Deleted: sha256:5df38afee6fffc1370a0f747ec044acf9348237856afb31562f889c144032d49
Deleted: sha256:f5472597a9440cee500059768ca8bdb6e78d736c0b593e89bcf4a67c3aa890fd
Deleted: sha256:cbfdc3b7c39bccab4555a658664a46d33e96238d1061f474648edf83a08c684c
Deleted: sha256:e1774d241e84a6f42088fe9b77d464e9eca7e342941ff88dcdbba0e012cddc6b
Build step 'Execute shell' marked build as failure