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:47:22 UTC

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

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

------------------------------------------
[...truncated 31.31 MB...]
3: I1012 07:47:17.932384 26311 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1012 07:47:17.932481 26311 registrar.cpp:424] Successfully recovered registrar
3: I1012 07:47:17.932821 26290 master.cpp:1791] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1012 07:47:17.932845 26296 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: W1012 07:47:17.937827 18190 process.cpp:3194] Attempted to spawn already running process files@172.17.0.2:46416
3: I1012 07:47:17.938683 18190 containerizer.cpp:292] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1012 07:47:17.939165 18190 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1012 07:47:17.939291 18190 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1012 07:47:17.939330 18190 provisioner.cpp:255] Using default backend 'copy'
3: I1012 07:47:17.941017 18190 cluster.cpp:448] Creating default 'local' authorizer
3: I1012 07:47:17.942898 26290 slave.cpp:254] Mesos agent started on (830)@172.17.0.2:46416
3: I1012 07:47:17.942921 26290 slave.cpp:255] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_OOMMRx/store/appc" --authenticate_http_executors="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_OOMMRx/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_OOMMRx/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_secret_key="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_OOMMRx/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_OOMMRx/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_OOMMRx/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_XhaYLS\/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_XhaYLS\/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_OOMMRx" --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_7R5RjI" --zk_session_timeout="10secs"
3: I1012 07:47:17.943286 26290 credentials.hpp:86] Loading credential for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_OOMMRx/credential'
3: W1012 07:47:17.943378 18190 process.cpp:3194] Attempted to spawn already running process version@172.17.0.2:46416
3: I1012 07:47:17.943426 26290 slave.cpp:287] Agent using credential for: test-principal
3: I1012 07:47:17.943444 26290 credentials.hpp:37] Loading credentials for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_OOMMRx/http_credentials'
3: I1012 07:47:17.943716 26290 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1012 07:47:17.943845 26290 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1012 07:47:17.944083 26290 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1012 07:47:17.944180 26290 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1012 07:47:17.944234 18190 sched.cpp:232] Version: 1.5.0
3: I1012 07:47:17.944388 26290 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1012 07:47:17.944481 26290 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1012 07:47:17.944772 26310 sched.cpp:336] New master detected at master@172.17.0.2:46416
3: I1012 07:47:17.944895 26310 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1012 07:47:17.944913 26310 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.2:46416
3: I1012 07:47:17.945021 26310 sched.cpp:853] Will retry registration in 288.547837ms if necessary
3: I1012 07:47:17.945206 26296 master.cpp:2929] Received SUBSCRIBE call for framework 'default' at scheduler-cc300f0c-67de-470f-a061-a428c5824e6c@172.17.0.2:46416
3: I1012 07:47:17.945232 26296 master.cpp:2263] Authorizing framework principal 'test-principal' to receive offers for roles '{ default-role }'
3: I1012 07:47:17.945690 26301 master.cpp:3009] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1012 07:47:17.946413 26288 sched.cpp:747] Framework registered with ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000
3: I1012 07:47:17.946465 26288 sched.cpp:761] Scheduler::registered took 33087ns
3: I1012 07:47:17.946584 26300 hierarchical.cpp:303] Added framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000
3: I1012 07:47:17.946727 26300 hierarchical.cpp:1943] No allocations performed
3: I1012 07:47:17.946751 26300 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 07:47:17.946787 26300 hierarchical.cpp:1486] Performed allocation for 0 agents in 103513ns
3: I1012 07:47:17.947625 26290 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_XhaYLS\/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_XhaYLS\/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:47:17.947962 26290 slave.cpp:593] Agent attributes: [  ]
3: I1012 07:47:17.947970 26290 slave.cpp:602] Agent hostname: 7239f06dd52c
3: I1012 07:47:17.948089 26309 status_update_manager.cpp:177] Pausing sending status updates
3: I1012 07:47:17.950194 26297 state.cpp:64] Recovering state from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_7R5RjI/meta'
3: I1012 07:47:17.950467 26307 status_update_manager.cpp:203] Recovering status update manager
3: I1012 07:47:17.950688 26302 containerizer.cpp:648] Recovering containerizer
3: I1012 07:47:17.952347 26309 provisioner.cpp:416] Provisioner recovery complete
3: I1012 07:47:17.952673 26295 slave.cpp:6310] Finished recovery
3: I1012 07:47:17.953104 26295 slave.cpp:6492] Querying resource estimator for oversubscribable resources
3: I1012 07:47:17.953330 26295 slave.cpp:993] New master detected at master@172.17.0.2:46416
3: I1012 07:47:17.953336 26303 status_update_manager.cpp:177] Pausing sending status updates
3: I1012 07:47:17.953374 26295 slave.cpp:1028] Detecting new master
3: I1012 07:47:17.953459 26295 slave.cpp:6506] Received oversubscribable resources {} from the resource estimator
3: I1012 07:47:17.953846 26297 slave.cpp:1055] Authenticating with master master@172.17.0.2:46416
3: I1012 07:47:17.953899 26297 slave.cpp:1064] Using default CRAM-MD5 authenticatee
3: I1012 07:47:17.954147 26292 authenticatee.cpp:121] Creating new client SASL connection
3: I1012 07:47:17.954206 26310 hierarchical.cpp:1943] No allocations performed
3: I1012 07:47:17.954243 26310 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 07:47:17.954268 26310 hierarchical.cpp:1486] Performed allocation for 0 agents in 96825ns
3: I1012 07:47:17.954426 26296 master.cpp:7936] Authenticating slave(830)@172.17.0.2:46416
3: I1012 07:47:17.954517 26311 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1497)@172.17.0.2:46416
3: I1012 07:47:17.954771 26289 authenticator.cpp:98] Creating new server SASL connection
3: I1012 07:47:17.954988 26306 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1012 07:47:17.955019 26306 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1012 07:47:17.955153 26301 authenticator.cpp:204] Received SASL authentication start
3: I1012 07:47:17.955209 26301 authenticator.cpp:326] Authentication requires more steps
3: I1012 07:47:17.955327 26302 authenticatee.cpp:259] Received SASL authentication step
3: I1012 07:47:17.955446 26288 authenticator.cpp:232] Received SASL authentication step
3: I1012 07:47:17.955476 26288 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '7239f06dd52c' server FQDN: '7239f06dd52c' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1012 07:47:17.955498 26288 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1012 07:47:17.955528 26288 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1012 07:47:17.955543 26288 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '7239f06dd52c' server FQDN: '7239f06dd52c' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1012 07:47:17.955550 26288 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1012 07:47:17.955554 26288 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1012 07:47:17.955580 26288 authenticator.cpp:318] Authentication success
3: I1012 07:47:17.955674 26293 authenticatee.cpp:299] Authentication success
3: I1012 07:47:17.955720 26291 master.cpp:7966] Successfully authenticated principal 'test-principal' at slave(830)@172.17.0.2:46416
3: I1012 07:47:17.955776 26309 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1497)@172.17.0.2:46416
3: I1012 07:47:17.955885 26300 slave.cpp:1147] Successfully authenticated with master master@172.17.0.2:46416
3: I1012 07:47:17.956146 26300 slave.cpp:1626] Will retry registration in 15.607787ms if necessary
3: I1012 07:47:17.956400 26303 master.cpp:5801] Received register agent message from slave(830)@172.17.0.2:46416 (7239f06dd52c)
3: I1012 07:47:17.956470 26303 master.cpp:3838] Authorizing agent with principal 'test-principal'
3: I1012 07:47:17.957051 26303 master.cpp:5861] Authorized registration of agent at slave(830)@172.17.0.2:46416 (7239f06dd52c)
3: I1012 07:47:17.957219 26303 master.cpp:5954] Registering agent at slave(830)@172.17.0.2:46416 (7239f06dd52c) with id ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0
3: I1012 07:47:17.957557 26295 registrar.cpp:495] Applied 1 operations in 89us; attempting to update the registry
3: I1012 07:47:17.958086 26295 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1012 07:47:17.958344 26292 master.cpp:6001] Admitted agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 at slave(830)@172.17.0.2:46416 (7239f06dd52c)
3: I1012 07:47:17.958932 26296 slave.cpp:4966] Received ping from slave-observer(746)@172.17.0.2:46416
3: I1012 07:47:17.959112 26306 slave.cpp:1193] Registered with master master@172.17.0.2:46416; given agent ID ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0
3: I1012 07:47:17.959200 26301 status_update_manager.cpp:184] Resuming sending status updates
3: I1012 07:47:17.959375 26306 slave.cpp:1213] Checkpointing SlaveInfo to '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_7R5RjI/meta/slaves/ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0/slave.info'
3: I1012 07:47:17.959038 26292 master.cpp:6032] Registered agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 at slave(830)@172.17.0.2:46416 (7239f06dd52c) 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_XhaYLS\/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_XhaYLS\/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:47:17.959517 26311 hierarchical.cpp:593] Added agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 (7239f06dd52c) with cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk2]:2048; ports:[31000-32000] (allocated: {})
3: I1012 07:47:17.959779 26306 slave.cpp:1262] Forwarding total oversubscribed resources {}
3: I1012 07:47:17.959964 26302 master.cpp:6817] Received update of agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 at slave(830)@172.17.0.2:46416 (7239f06dd52c) with total oversubscribed resources {}
3: I1012 07:47:17.960247 26302 master.cpp:6828] Ignoring update on agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 at slave(830)@172.17.0.2:46416 (7239f06dd52c) as it reports no changes
3: I1012 07:47:17.961648 26311 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 07:47:17.961683 26311 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.929256ms
3: I1012 07:47:17.962378 26293 master.cpp:7766] Sending 1 offers to framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000 (default) at scheduler-cc300f0c-67de-470f-a061-a428c5824e6c@172.17.0.2:46416
3: I1012 07:47:17.962899 26288 sched.cpp:917] Scheduler::resourceOffers took 113836ns
3: I1012 07:47:17.964678 26308 master.cpp:9389] Removing offer ab5e8811-dda9-48ec-82e7-4faab6640c2a-O0
3: I1012 07:47:17.964803 26308 master.cpp:4196] Processing ACCEPT call for offers: [ ab5e8811-dda9-48ec-82e7-4faab6640c2a-O0 ] on agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 at slave(830)@172.17.0.2:46416 (7239f06dd52c) for framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000 (default) at scheduler-cc300f0c-67de-470f-a061-a428c5824e6c@172.17.0.2:46416
3: I1012 07:47:17.964963 26308 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_XhaYLS\/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:47:17.965896 26308 master.cpp:2348] Dropping CREATE offer operation from framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000 (default) at scheduler-cc300f0c-67de-470f-a061-a428c5824e6c@172.17.0.2:46416: Not authorized to create persistent volumes as 'test-principal'
3: I1012 07:47:17.967188 26290 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_XhaYLS/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk2]:2048; ports:[31000-32000], allocated: {}) on agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 from framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000
3: I1012 07:47:17.969214 26304 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 07:47:17.969252 26304 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.603411ms
3: I1012 07:47:17.969830 26307 master.cpp:7766] Sending 1 offers to framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000 (default) at scheduler-cc300f0c-67de-470f-a061-a428c5824e6c@172.17.0.2:46416
3: I1012 07:47:17.970324 26305 sched.cpp:917] Scheduler::resourceOffers took 121897ns
3: I1012 07:47:17.970947 26295 master.cpp:5207] Processing DECLINE call for offers: [ ab5e8811-dda9-48ec-82e7-4faab6640c2a-O1 ] for framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000 (default) at scheduler-cc300f0c-67de-470f-a061-a428c5824e6c@172.17.0.2:46416
3: W1012 07:47:17.970985 18190 process.cpp:3194] Attempted to spawn already running process version@172.17.0.2:46416
3: I1012 07:47:17.971595 18190 sched.cpp:232] Version: 1.5.0
3: I1012 07:47:17.971752 26295 master.cpp:9389] Removing offer ab5e8811-dda9-48ec-82e7-4faab6640c2a-O1
3: I1012 07:47:17.971882 26295 master.cpp:3439] Processing SUPPRESS call for framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000 (default) at scheduler-cc300f0c-67de-470f-a061-a428c5824e6c@172.17.0.2:46416
3: I1012 07:47:17.972071 26306 sched.cpp:336] New master detected at master@172.17.0.2:46416
3: I1012 07:47:17.972177 26306 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1012 07:47:17.972189 26306 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.2:46416
3: I1012 07:47:17.972298 26306 sched.cpp:853] Will retry registration in 134.998687ms if necessary
3: I1012 07:47:17.972337 26296 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_XhaYLS/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk2]:2048; ports:[31000-32000], allocated: {}) on agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 from framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000
3: I1012 07:47:17.972473 26302 master.cpp:2929] Received SUBSCRIBE call for framework 'creator-framework' at scheduler-7b4a42c5-f895-4748-8a18-7e21a52fdb72@172.17.0.2:46416
3: I1012 07:47:17.972491 26302 master.cpp:2263] Authorizing framework principal 'creator-principal' to receive offers for roles '{ default-role }'
3: I1012 07:47:17.972493 26296 hierarchical.cpp:1273] Suppressed offers for roles { default-role } of framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000
3: I1012 07:47:17.972872 26288 master.cpp:3009] Subscribing framework creator-framework with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1012 07:47:17.973206 26291 hierarchical.cpp:303] Added framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001
3: I1012 07:47:17.973312 26299 sched.cpp:747] Framework registered with ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001
3: I1012 07:47:17.973350 26299 sched.cpp:761] Scheduler::registered took 20596ns
3: I1012 07:47:17.974732 26291 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 07:47:17.974769 26291 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.464619ms
3: I1012 07:47:17.975539 26309 master.cpp:7766] Sending 1 offers to framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001 (creator-framework) at scheduler-7b4a42c5-f895-4748-8a18-7e21a52fdb72@172.17.0.2:46416
3: I1012 07:47:17.976054 26298 sched.cpp:917] Scheduler::resourceOffers took 104971ns
3: I1012 07:47:17.976492 26308 hierarchical.cpp:1943] No allocations performed
3: I1012 07:47:17.976536 26308 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 07:47:17.976567 26308 hierarchical.cpp:1486] Performed allocation for 1 agents in 184497ns
3: I1012 07:47:17.978430 26304 master.cpp:9389] Removing offer ab5e8811-dda9-48ec-82e7-4faab6640c2a-O2
3: I1012 07:47:17.978581 26304 master.cpp:4196] Processing ACCEPT call for offers: [ ab5e8811-dda9-48ec-82e7-4faab6640c2a-O2 ] on agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 at slave(830)@172.17.0.2:46416 (7239f06dd52c) for framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001 (creator-framework) at scheduler-7b4a42c5-f895-4748-8a18-7e21a52fdb72@172.17.0.2:46416
3: I1012 07:47:17.978765 26304 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_XhaYLS\/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:47:17.980195 26304 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_XhaYLS\/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 ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001 (creator-framework) at scheduler-7b4a42c5-f895-4748-8a18-7e21a52fdb72@172.17.0.2:46416 to agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 at slave(830)@172.17.0.2:46416 (7239f06dd52c)
3: I1012 07:47:17.980844 26304 master.cpp:9335] Sending updated checkpointed resources disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk1,id1:path1]:2048 to agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 at slave(830)@172.17.0.2:46416 (7239f06dd52c)
3: I1012 07:47:17.981914 26289 slave.cpp:3519] Updated checkpointed resources from {} to disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk1,id1:path1]:2048
3: I1012 07:47:17.984520 26301 hierarchical.cpp:887] Updated allocation of framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001 on agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-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_XhaYLS/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/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_XhaYLS/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk1,id1:path1]:2048
3: I1012 07:47:17.986008 26301 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_XhaYLS/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk1,id1:path1]:2048, allocated: {}) on agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 from framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001
3: I1012 07:47:17.987941 26292 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 07:47:17.987979 26292 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.492314ms
3: I1012 07:47:17.988679 26306 master.cpp:7766] Sending 1 offers to framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001 (creator-framework) at scheduler-7b4a42c5-f895-4748-8a18-7e21a52fdb72@172.17.0.2:46416
3: I1012 07:47:17.989202 26311 sched.cpp:917] Scheduler::resourceOffers took 122753ns
3: I1012 07:47:17.989814 26302 master.cpp:5207] Processing DECLINE call for offers: [ ab5e8811-dda9-48ec-82e7-4faab6640c2a-O3 ] for framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001 (creator-framework) at scheduler-7b4a42c5-f895-4748-8a18-7e21a52fdb72@172.17.0.2:46416
3: I1012 07:47:17.990687 26302 master.cpp:9389] Removing offer ab5e8811-dda9-48ec-82e7-4faab6640c2a-O3
3: I1012 07:47:17.990818 26302 master.cpp:3439] Processing SUPPRESS call for framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001 (creator-framework) at scheduler-7b4a42c5-f895-4748-8a18-7e21a52fdb72@172.17.0.2:46416
3: I1012 07:47:17.991416 26293 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_XhaYLS/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk1,id1:path1]:2048, allocated: {}) on agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 from framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001
3: I1012 07:47:17.991565 26293 hierarchical.cpp:1273] Suppressed offers for roles { default-role } of framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001
3: I1012 07:47:17.991951 26294 master.cpp:5312] Processing REVIVE call for framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000 (default) at scheduler-cc300f0c-67de-470f-a061-a428c5824e6c@172.17.0.2:46416
3: I1012 07:47:17.992076 26299 hierarchical.cpp:1308] Revived offers for roles { default-role } of framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000
3: I1012 07:47:17.993571 26299 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 07:47:17.993602 26299 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.43138ms
3: I1012 07:47:17.994314 26291 master.cpp:7766] Sending 1 offers to framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000 (default) at scheduler-cc300f0c-67de-470f-a061-a428c5824e6c@172.17.0.2:46416
3: I1012 07:47:17.994832 26309 sched.cpp:917] Scheduler::resourceOffers took 112887ns
3: I1012 07:47:17.996287 26300 master.cpp:9389] Removing offer ab5e8811-dda9-48ec-82e7-4faab6640c2a-O4
3: I1012 07:47:17.996417 26300 master.cpp:4196] Processing ACCEPT call for offers: [ ab5e8811-dda9-48ec-82e7-4faab6640c2a-O4 ] on agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 at slave(830)@172.17.0.2:46416 (7239f06dd52c) for framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000 (default) at scheduler-cc300f0c-67de-470f-a061-a428c5824e6c@172.17.0.2:46416
3: I1012 07:47:17.996556 26300 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_XhaYLS\/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:47:17.997457 26300 master.cpp:2348] Dropping DESTROY offer operation from framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000 (default) at scheduler-cc300f0c-67de-470f-a061-a428c5824e6c@172.17.0.2:46416: Not authorized to destroy persistent volumes as 'test-principal'
3: I1012 07:47:17.998809 26297 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_XhaYLS/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk1,id1:path1]:2048, allocated: {}) on agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 from framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000
3: I1012 07:47:18.000772 26304 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 07:47:18.000809 26304 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.48889ms
3: I1012 07:47:18.001488 26289 master.cpp:7766] Sending 1 offers to framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000 (default) at scheduler-cc300f0c-67de-470f-a061-a428c5824e6c@172.17.0.2:46416
3: I1012 07:47:18.001937 26301 sched.cpp:917] Scheduler::resourceOffers took 100497ns
3: I1012 07:47:18.002251 18190 sched.cpp:2005] Asked to stop the driver
3: I1012 07:47:18.002343 26295 sched.cpp:1187] Stopping framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000
3: I1012 07:47:18.002573 18190 sched.cpp:2005] Asked to stop the driver
3: I1012 07:47:18.002575 26292 master.cpp:8447] Processing TEARDOWN call for framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000 (default) at scheduler-cc300f0c-67de-470f-a061-a428c5824e6c@172.17.0.2:46416
3: I1012 07:47:18.002602 26292 master.cpp:8459] Removing framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000 (default) at scheduler-cc300f0c-67de-470f-a061-a428c5824e6c@172.17.0.2:46416
3: I1012 07:47:18.002621 26292 master.cpp:3299] Deactivating framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000 (default) at scheduler-cc300f0c-67de-470f-a061-a428c5824e6c@172.17.0.2:46416
3: I1012 07:47:18.002635 26296 sched.cpp:1187] Stopping framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001
3: I1012 07:47:18.002737 26302 hierarchical.cpp:412] Deactivated framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000
3: I1012 07:47:18.003513 26292 master.cpp:9389] Removing offer ab5e8811-dda9-48ec-82e7-4faab6640c2a-O5
3: I1012 07:47:18.003726 26307 slave.cpp:3211] Asked to shut down framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000 by master@172.17.0.2:46416
3: I1012 07:47:18.003767 26307 slave.cpp:3226] Cannot shut down unknown framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000
3: I1012 07:47:18.004029 26292 master.cpp:8447] Processing TEARDOWN call for framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001 (creator-framework) at scheduler-7b4a42c5-f895-4748-8a18-7e21a52fdb72@172.17.0.2:46416
3: I1012 07:47:18.004052 26292 master.cpp:8459] Removing framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001 (creator-framework) at scheduler-7b4a42c5-f895-4748-8a18-7e21a52fdb72@172.17.0.2:46416
3: I1012 07:47:18.004067 26292 master.cpp:3299] Deactivating framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001 (creator-framework) at scheduler-7b4a42c5-f895-4748-8a18-7e21a52fdb72@172.17.0.2:46416
3: I1012 07:47:18.004221 26296 slave.cpp:3211] Asked to shut down framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001 by master@172.17.0.2:46416
3: I1012 07:47:18.004247 26296 slave.cpp:3226] Cannot shut down unknown framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001
3: I1012 07:47:18.004355 26294 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_XhaYLS/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhaYLS/disk1,id1:path1]:2048, allocated: {}) on agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 from framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000
3: I1012 07:47:18.004637 26294 hierarchical.cpp:355] Removed framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0000
3: I1012 07:47:18.004696 26294 hierarchical.cpp:412] Deactivated framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001
3: I1012 07:47:18.004905 26294 hierarchical.cpp:355] Removed framework ab5e8811-dda9-48ec-82e7-4faab6640c2a-0001
3: I1012 07:47:18.005101 26297 slave.cpp:869] Agent terminating
3: I1012 07:47:18.005282 26307 master.cpp:1303] Agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 at slave(830)@172.17.0.2:46416 (7239f06dd52c) disconnected
3: I1012 07:47:18.005300 26307 master.cpp:3336] Disconnecting agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 at slave(830)@172.17.0.2:46416 (7239f06dd52c)
3: I1012 07:47:18.005357 26307 master.cpp:3355] Deactivating agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 at slave(830)@172.17.0.2:46416 (7239f06dd52c)
3: I1012 07:47:18.005481 26301 hierarchical.cpp:690] Agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0 deactivated
3: I1012 07:47:18.010468 18190 master.cpp:1145] Master terminating
3: I1012 07:47:18.011374 26303 hierarchical.cpp:626] Removed agent ab5e8811-dda9-48ec-82e7-4faab6640c2a-S0
3: [       OK ] DiskResource/PersistentVolumeTest.BadACLDropCreateAndDestroy/1 (94 ms)
3: [----------] 34 tests from DiskResource/PersistentVolumeTest (10852 ms total)
3: 
3: [----------] Global test environment tear-down
3: [==========] 1656 tests from 180 test cases ran. (314062 ms total)
3: [  PASSED  ] 1655 tests.
3: [  FAILED  ] 1 test, listed below:
3: [  FAILED  ] OversubscriptionTest.RescindRevocableOfferWithIncreasedRevocable
3: 
3:  1 FAILED TEST
3:   YOU HAVE 21 DISABLED TESTS
3: 
3: I1012 07:47:18.070870 26312 process.cpp:1068] Failed to accept socket: future discarded
3/3 Test #3: MesosTests .......................***Failed  318.93 sec

67% tests passed, 1 tests failed out of 3

Total Test time (real) = 361.30 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-1507792535-16940
Untagged: mesos-1507792535-16940:latest
Deleted: sha256:fd902f6380adc51fa00905f9f8b6f90de8b66def3efe910bda1b74688cf048ae
Deleted: sha256:2d1b3dacd11498fe502cf162a5608e3815938b589426c350193fddcce4b5307d
Deleted: sha256:6876f16e6ea7183aaadda6fe76435628628c5efb896e6527e2a32498ed252535
Deleted: sha256:14c20d272b64e9a22e183fe4043b5df0f17974a20b394bee8ac6ed06b79b277b
Deleted: sha256:02ddb4b563cf11c68fee5eb3ad1feb4e17281e79563dc543c08e7581a07586e0
Deleted: sha256:cd39432952cab4bcc645c91445fce71841ca1c82f72fbd2e169e1e220b17816d
Deleted: sha256:eea51249806fd65a06e8a6e60444fd8b2dfda1cb880a0c855afe7d14581bd03b
Deleted: sha256:813e59062a7249ef418ce7fb5467bdfadee25f2a26e07ef87debf31456715d43
Deleted: sha256:f8f436e229f27445bc49841c8f4087004f5154afa5ff30b6517ba89381de3da4
Deleted: sha256:8b13796437625234173b7b9b7ac8e1b6757f8752b4afc4fff8ba7e4efa4c2071
Deleted: sha256:00317130e776d9f6816c3698fc00fbe42f2f15ba7526015a6ce8eb8b6d854f50
Deleted: sha256:97c79eb625d4d5643ecbbcae6dfb87802ddc95a0ba79c5a098d80f3c60f1c0ae
Deleted: sha256:d59362f4637bacc5213505364be7e20bb2712164178fb21fe060eb84e2c5c4e9
Deleted: sha256:076019233c776bcd45595b752d513d95a9877e815ae36d973f064069263a74e6
Deleted: sha256:e790ea883e95ac9c0b233f193dd2c82a9984e9570227cf6b71149e260b622b52
Deleted: sha256:85c3f92d9e726c7cad0758558dd2a19ca1e1a770d56afb3fa921bc47d3090162
Deleted: sha256:0669529f3fdb67546f69bd9efb999ebfcaf34ef59ca8ac0071e7bff5e53057e4
Deleted: sha256:13d3e849dad34b66a42e83bfd524c2613098894207db36dee8d8ee8de60da99e
Deleted: sha256:0253b8c8882cda68bda3f408b595d6a4ceb1a218fa23bfc2f44a2683c8fff9f4
Deleted: sha256:e3116ef2f1591cff261c56b82bdf0431349aefb8b610e3a59d1102982af80573
Deleted: sha256:6566b47a2769c5851c358cd6b4d9fb94b64171d6f20fc04c72e5016b9b8b4bb4
Deleted: sha256:1868a5325ba4edb063ffa2045d5725e249184e0b19e2f4977a5ae053509ae67c
Deleted: sha256:7db06ddc6f1fa760b7e93f1edf33bd7d74de314377d5587b8367de781c17bbee
Deleted: sha256:15502001480e926546ba84f5610a0800f364bfdb724c1cf24ba158cc918125c8
Deleted: sha256:2e81966e02e972da797383cdac9572570fb2802f851d68350d756ea25f223c1b
Deleted: sha256:72386fd1ee42920ad0c0bbb66a0f9b6f482f5ca4ddfb219d6e3adcdc25eaa0bd
Deleted: sha256:aa9a7e4e2471a191d21afa2b88a43d871899d94938ece60c812e232f82140840
Deleted: sha256:ef6338ff7710614e8d5318a8eb9950d4e6376a86108ead4a3ea0fc68b5fdda60
Build step 'Execute shell' marked build as failure


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

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


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

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

Changes:

[jpeach] Removed support for platforms without O_CLOEXEC.

[jpeach] Document the Linux build requirements.

[xujyan] Fixed flaky test SharedPersistentVolumeRescindOnDestroy.

[yujie.jay] Synced the MTU for container eth0 in port mapping isolator.

------------------------------------------
[...truncated 31.91 MB...]
3: W1012 23:00:56.333060 18187 process.cpp:3194] Attempted to spawn already running process files@172.17.0.4:36625
3: I1012 23:00:56.333932 18187 containerizer.cpp:292] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1012 23:00:56.334383 18187 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1012 23:00:56.334498 18187 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1012 23:00:56.334528 18187 provisioner.cpp:255] Using default backend 'copy'
3: I1012 23:00:56.336355 18187 cluster.cpp:448] Creating default 'local' authorizer
3: I1012 23:00:56.338316 26293 slave.cpp:254] Mesos agent started on (830)@172.17.0.4:36625
3: W1012 23:00:56.338879 18187 process.cpp:3194] Attempted to spawn already running process version@172.17.0.4:36625
3: I1012 23:00:56.338348 26293 slave.cpp:255] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhfuwT/store/appc" --authenticate_http_executors="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhfuwT/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_XhfuwT/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_secret_key="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhfuwT/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhfuwT/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_XhfuwT/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_088kjV\/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_088kjV\/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_XhfuwT" --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_QV4TpU" --zk_session_timeout="10secs"
3: I1012 23:00:56.339027 26293 credentials.hpp:86] Loading credential for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhfuwT/credential'
3: I1012 23:00:56.339252 26293 slave.cpp:287] Agent using credential for: test-principal
3: I1012 23:00:56.339274 26293 credentials.hpp:37] Loading credentials for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_XhfuwT/http_credentials'
3: I1012 23:00:56.339546 26293 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1012 23:00:56.339743 26293 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1012 23:00:56.339810 18187 sched.cpp:232] Version: 1.5.0
3: I1012 23:00:56.339978 26293 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1012 23:00:56.340098 26293 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1012 23:00:56.340319 26293 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1012 23:00:56.340446 26293 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1012 23:00:56.340450 26278 sched.cpp:336] New master detected at master@172.17.0.4:36625
3: I1012 23:00:56.340628 26278 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1012 23:00:56.340642 26278 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.4:36625
3: I1012 23:00:56.340796 26278 sched.cpp:853] Will retry registration in 668.690507ms if necessary
3: I1012 23:00:56.340999 26298 master.cpp:2929] Received SUBSCRIBE call for framework 'default' at scheduler-f141a936-a418-4894-8e2f-f606923f16c9@172.17.0.4:36625
3: I1012 23:00:56.341022 26298 master.cpp:2263] Authorizing framework principal 'test-principal' to receive offers for roles '{ default-role }'
3: I1012 23:00:56.341505 26292 master.cpp:3009] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1012 23:00:56.342151 26295 sched.cpp:747] Framework registered with 961baa25-b095-4d16-92cd-6dce3d6ea261-0000
3: I1012 23:00:56.342217 26295 sched.cpp:761] Scheduler::registered took 42605ns
3: I1012 23:00:56.342244 26297 hierarchical.cpp:303] Added framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000
3: I1012 23:00:56.342416 26297 hierarchical.cpp:1943] No allocations performed
3: I1012 23:00:56.342450 26297 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 23:00:56.342475 26297 hierarchical.cpp:1486] Performed allocation for 0 agents in 107535ns
3: I1012 23:00:56.343822 26293 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_088kjV\/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_088kjV\/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 23:00:56.344179 26293 slave.cpp:593] Agent attributes: [  ]
3: I1012 23:00:56.344189 26293 slave.cpp:602] Agent hostname: 7fc29d10deac
3: I1012 23:00:56.344305 26280 status_update_manager.cpp:177] Pausing sending status updates
3: I1012 23:00:56.345755 26290 state.cpp:64] Recovering state from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QV4TpU/meta'
3: I1012 23:00:56.346060 26294 status_update_manager.cpp:203] Recovering status update manager
3: I1012 23:00:56.346240 26283 containerizer.cpp:648] Recovering containerizer
3: I1012 23:00:56.347569 26284 provisioner.cpp:416] Provisioner recovery complete
3: I1012 23:00:56.347883 26279 slave.cpp:6310] Finished recovery
3: I1012 23:00:56.348321 26279 slave.cpp:6492] Querying resource estimator for oversubscribable resources
3: I1012 23:00:56.348592 26286 status_update_manager.cpp:177] Pausing sending status updates
3: I1012 23:00:56.348605 26293 slave.cpp:993] New master detected at master@172.17.0.4:36625
3: I1012 23:00:56.348659 26293 slave.cpp:1028] Detecting new master
3: I1012 23:00:56.348770 26293 slave.cpp:6506] Received oversubscribable resources {} from the resource estimator
3: I1012 23:00:56.349112 26288 slave.cpp:1055] Authenticating with master master@172.17.0.4:36625
3: I1012 23:00:56.349176 26288 slave.cpp:1064] Using default CRAM-MD5 authenticatee
3: I1012 23:00:56.349478 26288 authenticatee.cpp:121] Creating new client SASL connection
3: I1012 23:00:56.349707 26291 hierarchical.cpp:1943] No allocations performed
3: I1012 23:00:56.349756 26291 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 23:00:56.349779 26287 master.cpp:7936] Authenticating slave(830)@172.17.0.4:36625
3: I1012 23:00:56.349792 26291 hierarchical.cpp:1486] Performed allocation for 0 agents in 225780ns
3: I1012 23:00:56.349897 26282 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1498)@172.17.0.4:36625
3: I1012 23:00:56.350222 26300 authenticator.cpp:98] Creating new server SASL connection
3: I1012 23:00:56.350448 26278 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1012 23:00:56.350473 26278 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1012 23:00:56.350566 26278 authenticator.cpp:204] Received SASL authentication start
3: I1012 23:00:56.350625 26278 authenticator.cpp:326] Authentication requires more steps
3: I1012 23:00:56.350729 26292 authenticatee.cpp:259] Received SASL authentication step
3: I1012 23:00:56.350850 26298 authenticator.cpp:232] Received SASL authentication step
3: I1012 23:00:56.350878 26298 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '7fc29d10deac' server FQDN: '7fc29d10deac' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1012 23:00:56.350894 26298 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1012 23:00:56.350942 26298 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1012 23:00:56.350970 26298 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '7fc29d10deac' server FQDN: '7fc29d10deac' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1012 23:00:56.350980 26298 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1012 23:00:56.350988 26298 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1012 23:00:56.351006 26298 authenticator.cpp:318] Authentication success
3: I1012 23:00:56.351094 26296 authenticatee.cpp:299] Authentication success
3: I1012 23:00:56.351205 26296 master.cpp:7966] Successfully authenticated principal 'test-principal' at slave(830)@172.17.0.4:36625
3: I1012 23:00:56.351275 26298 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1498)@172.17.0.4:36625
3: I1012 23:00:56.351467 26295 slave.cpp:1147] Successfully authenticated with master master@172.17.0.4:36625
3: I1012 23:00:56.351860 26295 slave.cpp:1626] Will retry registration in 4.720543ms if necessary
3: I1012 23:00:56.352159 26286 master.cpp:5801] Received register agent message from slave(830)@172.17.0.4:36625 (7fc29d10deac)
3: I1012 23:00:56.352208 26286 master.cpp:3838] Authorizing agent with principal 'test-principal'
3: I1012 23:00:56.352768 26286 master.cpp:5861] Authorized registration of agent at slave(830)@172.17.0.4:36625 (7fc29d10deac)
3: I1012 23:00:56.352908 26286 master.cpp:5954] Registering agent at slave(830)@172.17.0.4:36625 (7fc29d10deac) with id 961baa25-b095-4d16-92cd-6dce3d6ea261-S0
3: I1012 23:00:56.353292 26290 registrar.cpp:495] Applied 1 operations in 83314ns; attempting to update the registry
3: I1012 23:00:56.353888 26290 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1012 23:00:56.354101 26288 master.cpp:6001] Admitted agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 at slave(830)@172.17.0.4:36625 (7fc29d10deac)
3: I1012 23:00:56.354746 26291 slave.cpp:4966] Received ping from slave-observer(746)@172.17.0.4:36625
3: I1012 23:00:56.354907 26291 slave.cpp:1193] Registered with master master@172.17.0.4:36625; given agent ID 961baa25-b095-4d16-92cd-6dce3d6ea261-S0
3: I1012 23:00:56.355013 26283 status_update_manager.cpp:184] Resuming sending status updates
3: I1012 23:00:56.354818 26288 master.cpp:6032] Registered agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 at slave(830)@172.17.0.4:36625 (7fc29d10deac) 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_088kjV\/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_088kjV\/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 23:00:56.355321 26291 slave.cpp:1213] Checkpointing SlaveInfo to '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QV4TpU/meta/slaves/961baa25-b095-4d16-92cd-6dce3d6ea261-S0/slave.info'
3: I1012 23:00:56.355542 26282 hierarchical.cpp:593] Added agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 (7fc29d10deac) with cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk2]:2048; ports:[31000-32000] (allocated: {})
3: I1012 23:00:56.355762 26291 slave.cpp:1262] Forwarding total oversubscribed resources {}
3: I1012 23:00:56.355959 26291 master.cpp:6817] Received update of agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 at slave(830)@172.17.0.4:36625 (7fc29d10deac) with total oversubscribed resources {}
3: I1012 23:00:56.356258 26291 master.cpp:6828] Ignoring update on agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 at slave(830)@172.17.0.4:36625 (7fc29d10deac) as it reports no changes
3: I1012 23:00:56.357307 26282 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 23:00:56.357344 26282 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.639585ms
3: I1012 23:00:56.358018 26292 master.cpp:7766] Sending 1 offers to framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000 (default) at scheduler-f141a936-a418-4894-8e2f-f606923f16c9@172.17.0.4:36625
3: I1012 23:00:56.358563 26289 sched.cpp:917] Scheduler::resourceOffers took 106663ns
3: I1012 23:00:56.360311 26284 master.cpp:9389] Removing offer 961baa25-b095-4d16-92cd-6dce3d6ea261-O0
3: I1012 23:00:56.360440 26284 master.cpp:4196] Processing ACCEPT call for offers: [ 961baa25-b095-4d16-92cd-6dce3d6ea261-O0 ] on agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 at slave(830)@172.17.0.4:36625 (7fc29d10deac) for framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000 (default) at scheduler-f141a936-a418-4894-8e2f-f606923f16c9@172.17.0.4:36625
3: I1012 23:00:56.360605 26284 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_088kjV\/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 23:00:56.361526 26284 master.cpp:2348] Dropping CREATE offer operation from framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000 (default) at scheduler-f141a936-a418-4894-8e2f-f606923f16c9@172.17.0.4:36625: Not authorized to create persistent volumes as 'test-principal'
3: I1012 23:00:56.363708 26295 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_088kjV/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk2]:2048; ports:[31000-32000], allocated: {}) on agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 from framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000
3: I1012 23:00:56.366626 26286 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 23:00:56.366686 26286 hierarchical.cpp:1486] Performed allocation for 1 agents in 2.407915ms
3: I1012 23:00:56.367280 26294 master.cpp:7766] Sending 1 offers to framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000 (default) at scheduler-f141a936-a418-4894-8e2f-f606923f16c9@172.17.0.4:36625
3: I1012 23:00:56.367760 26285 sched.cpp:917] Scheduler::resourceOffers took 100959ns
3: I1012 23:00:56.368366 26301 master.cpp:5207] Processing DECLINE call for offers: [ 961baa25-b095-4d16-92cd-6dce3d6ea261-O1 ] for framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000 (default) at scheduler-f141a936-a418-4894-8e2f-f606923f16c9@172.17.0.4:36625
3: W1012 23:00:56.368501 18187 process.cpp:3194] Attempted to spawn already running process version@172.17.0.4:36625
3: I1012 23:00:56.369138 26301 master.cpp:9389] Removing offer 961baa25-b095-4d16-92cd-6dce3d6ea261-O1
3: I1012 23:00:56.369264 26301 master.cpp:3439] Processing SUPPRESS call for framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000 (default) at scheduler-f141a936-a418-4894-8e2f-f606923f16c9@172.17.0.4:36625
3: I1012 23:00:56.369285 18187 sched.cpp:232] Version: 1.5.0
3: I1012 23:00:56.369835 26290 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_088kjV/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk2]:2048; ports:[31000-32000], allocated: {}) on agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 from framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000
3: I1012 23:00:56.369891 26291 sched.cpp:336] New master detected at master@172.17.0.4:36625
3: I1012 23:00:56.369997 26290 hierarchical.cpp:1273] Suppressed offers for roles { default-role } of framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000
3: I1012 23:00:56.370028 26291 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1012 23:00:56.370040 26291 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.4:36625
3: I1012 23:00:56.370157 26291 sched.cpp:853] Will retry registration in 672.570796ms if necessary
3: I1012 23:00:56.370318 26278 master.cpp:2929] Received SUBSCRIBE call for framework 'creator-framework' at scheduler-e4d9dd11-9f1b-4b19-9849-5113d3f7f4f8@172.17.0.4:36625
3: I1012 23:00:56.370342 26278 master.cpp:2263] Authorizing framework principal 'creator-principal' to receive offers for roles '{ default-role }'
3: I1012 23:00:56.370831 26289 master.cpp:3009] Subscribing framework creator-framework with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1012 23:00:56.371299 26297 hierarchical.cpp:303] Added framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0001
3: I1012 23:00:56.371402 26289 sched.cpp:747] Framework registered with 961baa25-b095-4d16-92cd-6dce3d6ea261-0001
3: I1012 23:00:56.371444 26289 sched.cpp:761] Scheduler::registered took 22715ns
3: I1012 23:00:56.372889 26297 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 23:00:56.372926 26297 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.490533ms
3: I1012 23:00:56.373625 26280 master.cpp:7766] Sending 1 offers to framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0001 (creator-framework) at scheduler-e4d9dd11-9f1b-4b19-9849-5113d3f7f4f8@172.17.0.4:36625
3: I1012 23:00:56.374162 26296 sched.cpp:917] Scheduler::resourceOffers took 110500ns
3: I1012 23:00:56.374753 26295 hierarchical.cpp:1943] No allocations performed
3: I1012 23:00:56.374806 26295 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 23:00:56.374857 26295 hierarchical.cpp:1486] Performed allocation for 1 agents in 229408ns
3: I1012 23:00:56.377321 26286 master.cpp:9389] Removing offer 961baa25-b095-4d16-92cd-6dce3d6ea261-O2
3: I1012 23:00:56.377486 26286 master.cpp:4196] Processing ACCEPT call for offers: [ 961baa25-b095-4d16-92cd-6dce3d6ea261-O2 ] on agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 at slave(830)@172.17.0.4:36625 (7fc29d10deac) for framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0001 (creator-framework) at scheduler-e4d9dd11-9f1b-4b19-9849-5113d3f7f4f8@172.17.0.4:36625
3: I1012 23:00:56.377682 26286 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_088kjV\/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 23:00:56.379747 26286 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_088kjV\/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 961baa25-b095-4d16-92cd-6dce3d6ea261-0001 (creator-framework) at scheduler-e4d9dd11-9f1b-4b19-9849-5113d3f7f4f8@172.17.0.4:36625 to agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 at slave(830)@172.17.0.4:36625 (7fc29d10deac)
3: I1012 23:00:56.380591 26286 master.cpp:9335] Sending updated checkpointed resources disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk1,id1:path1]:2048 to agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 at slave(830)@172.17.0.4:36625 (7fc29d10deac)
3: I1012 23:00:56.381824 26300 slave.cpp:3519] Updated checkpointed resources from {} to disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk1,id1:path1]:2048
3: I1012 23:00:56.385530 26283 hierarchical.cpp:887] Updated allocation of framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0001 on agent 961baa25-b095-4d16-92cd-6dce3d6ea261-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_088kjV/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/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_088kjV/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk1,id1:path1]:2048
3: I1012 23:00:56.387429 26283 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_088kjV/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk1,id1:path1]:2048, allocated: {}) on agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 from framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0001
3: I1012 23:00:56.389322 26290 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 23:00:56.389366 26290 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.444488ms
3: I1012 23:00:56.390365 26291 master.cpp:7766] Sending 1 offers to framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0001 (creator-framework) at scheduler-e4d9dd11-9f1b-4b19-9849-5113d3f7f4f8@172.17.0.4:36625
3: I1012 23:00:56.391026 26282 sched.cpp:917] Scheduler::resourceOffers took 124386ns
3: I1012 23:00:56.391734 26292 master.cpp:5207] Processing DECLINE call for offers: [ 961baa25-b095-4d16-92cd-6dce3d6ea261-O3 ] for framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0001 (creator-framework) at scheduler-e4d9dd11-9f1b-4b19-9849-5113d3f7f4f8@172.17.0.4:36625
3: I1012 23:00:56.392606 26292 master.cpp:9389] Removing offer 961baa25-b095-4d16-92cd-6dce3d6ea261-O3
3: I1012 23:00:56.392761 26292 master.cpp:3439] Processing SUPPRESS call for framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0001 (creator-framework) at scheduler-e4d9dd11-9f1b-4b19-9849-5113d3f7f4f8@172.17.0.4:36625
3: I1012 23:00:56.393465 26279 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_088kjV/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk1,id1:path1]:2048, allocated: {}) on agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 from framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0001
3: I1012 23:00:56.393635 26279 hierarchical.cpp:1273] Suppressed offers for roles { default-role } of framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0001
3: I1012 23:00:56.394007 26289 master.cpp:5312] Processing REVIVE call for framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000 (default) at scheduler-f141a936-a418-4894-8e2f-f606923f16c9@172.17.0.4:36625
3: I1012 23:00:56.394132 26297 hierarchical.cpp:1308] Revived offers for roles { default-role } of framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000
3: I1012 23:00:56.395521 26297 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 23:00:56.395555 26297 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.326706ms
3: I1012 23:00:56.396306 26280 master.cpp:7766] Sending 1 offers to framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000 (default) at scheduler-f141a936-a418-4894-8e2f-f606923f16c9@172.17.0.4:36625
3: I1012 23:00:56.396860 26296 sched.cpp:917] Scheduler::resourceOffers took 111554ns
3: I1012 23:00:56.398483 26284 master.cpp:9389] Removing offer 961baa25-b095-4d16-92cd-6dce3d6ea261-O4
3: I1012 23:00:56.398608 26284 master.cpp:4196] Processing ACCEPT call for offers: [ 961baa25-b095-4d16-92cd-6dce3d6ea261-O4 ] on agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 at slave(830)@172.17.0.4:36625 (7fc29d10deac) for framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000 (default) at scheduler-f141a936-a418-4894-8e2f-f606923f16c9@172.17.0.4:36625
3: I1012 23:00:56.398761 26284 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_088kjV\/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 23:00:56.399785 26284 master.cpp:2348] Dropping DESTROY offer operation from framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000 (default) at scheduler-f141a936-a418-4894-8e2f-f606923f16c9@172.17.0.4:36625: Not authorized to destroy persistent volumes as 'test-principal'
3: I1012 23:00:56.401190 26301 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_088kjV/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk1,id1:path1]:2048, allocated: {}) on agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 from framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000
3: I1012 23:00:56.404115 26286 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 23:00:56.404172 26286 hierarchical.cpp:1486] Performed allocation for 1 agents in 2.337791ms
3: I1012 23:00:56.404825 26300 master.cpp:7766] Sending 1 offers to framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000 (default) at scheduler-f141a936-a418-4894-8e2f-f606923f16c9@172.17.0.4:36625
3: I1012 23:00:56.405495 26283 sched.cpp:917] Scheduler::resourceOffers took 150786ns
3: I1012 23:00:56.405825 18187 sched.cpp:2005] Asked to stop the driver
3: I1012 23:00:56.405926 26288 sched.cpp:1187] Stopping framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000
3: I1012 23:00:56.406220 26290 master.cpp:8447] Processing TEARDOWN call for framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000 (default) at scheduler-f141a936-a418-4894-8e2f-f606923f16c9@172.17.0.4:36625
3: I1012 23:00:56.406250 26290 master.cpp:8459] Removing framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000 (default) at scheduler-f141a936-a418-4894-8e2f-f606923f16c9@172.17.0.4:36625
3: I1012 23:00:56.406265 18187 sched.cpp:2005] Asked to stop the driver
3: I1012 23:00:56.406268 26290 master.cpp:3299] Deactivating framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000 (default) at scheduler-f141a936-a418-4894-8e2f-f606923f16c9@172.17.0.4:36625
3: I1012 23:00:56.406353 26278 sched.cpp:1187] Stopping framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0001
3: I1012 23:00:56.406405 26292 hierarchical.cpp:412] Deactivated framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000
3: I1012 23:00:56.407522 26290 master.cpp:9389] Removing offer 961baa25-b095-4d16-92cd-6dce3d6ea261-O5
3: I1012 23:00:56.407757 26286 slave.cpp:3211] Asked to shut down framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000 by master@172.17.0.4:36625
3: I1012 23:00:56.407790 26286 slave.cpp:3226] Cannot shut down unknown framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000
3: I1012 23:00:56.408126 26290 master.cpp:8447] Processing TEARDOWN call for framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0001 (creator-framework) at scheduler-e4d9dd11-9f1b-4b19-9849-5113d3f7f4f8@172.17.0.4:36625
3: I1012 23:00:56.408149 26290 master.cpp:8459] Removing framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0001 (creator-framework) at scheduler-e4d9dd11-9f1b-4b19-9849-5113d3f7f4f8@172.17.0.4:36625
3: I1012 23:00:56.408159 26290 master.cpp:3299] Deactivating framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0001 (creator-framework) at scheduler-e4d9dd11-9f1b-4b19-9849-5113d3f7f4f8@172.17.0.4:36625
3: I1012 23:00:56.408318 26281 slave.cpp:3211] Asked to shut down framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0001 by master@172.17.0.4:36625
3: I1012 23:00:56.408349 26281 slave.cpp:3226] Cannot shut down unknown framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0001
3: I1012 23:00:56.408551 26289 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_088kjV/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_088kjV/disk1,id1:path1]:2048, allocated: {}) on agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 from framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000
3: I1012 23:00:56.408753 26289 hierarchical.cpp:355] Removed framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0000
3: I1012 23:00:56.408813 26289 hierarchical.cpp:412] Deactivated framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0001
3: I1012 23:00:56.409015 26289 hierarchical.cpp:355] Removed framework 961baa25-b095-4d16-92cd-6dce3d6ea261-0001
3: I1012 23:00:56.409220 18187 slave.cpp:869] Agent terminating
3: I1012 23:00:56.409385 26286 master.cpp:1303] Agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 at slave(830)@172.17.0.4:36625 (7fc29d10deac) disconnected
3: I1012 23:00:56.409412 26286 master.cpp:3336] Disconnecting agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 at slave(830)@172.17.0.4:36625 (7fc29d10deac)
3: I1012 23:00:56.409485 26286 master.cpp:3355] Deactivating agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 at slave(830)@172.17.0.4:36625 (7fc29d10deac)
3: I1012 23:00:56.409615 26282 hierarchical.cpp:690] Agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0 deactivated
3: I1012 23:00:56.415213 18187 master.cpp:1145] Master terminating
3: I1012 23:00:56.416141 26285 hierarchical.cpp:626] Removed agent 961baa25-b095-4d16-92cd-6dce3d6ea261-S0
3: [       OK ] DiskResource/PersistentVolumeTest.BadACLDropCreateAndDestroy/1 (105 ms)
3: [----------] 34 tests from DiskResource/PersistentVolumeTest (11292 ms total)
3: 
3: [----------] Global test environment tear-down
3: [==========] 1656 tests from 180 test cases ran. (361603 ms total)
3: [  PASSED  ] 1653 tests.
3: [  FAILED  ] 3 tests, listed below:
3: [  FAILED  ] ExecutorAuthorizationTest.RunTaskGroup
3: [  FAILED  ] SlaveTest.RestartSlaveRequireExecutorAuthentication
3: [  FAILED  ] SlaveRecoveryTest/0.RemoveNonCheckpointingFramework, where TypeParam = mesos::internal::slave::MesosContainerizer
3: 
3:  3 FAILED TESTS
3:   YOU HAVE 21 DISABLED TESTS
3: 
3: I1012 23:00:56.475662 26302 process.cpp:1068] Failed to accept socket: future discarded
3/3 Test #3: MesosTests .......................***Failed  366.06 sec

67% tests passed, 1 tests failed out of 3

Total Test time (real) = 404.81 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-1507847375-17366
Untagged: mesos-1507847375-17366:latest
Deleted: sha256:584da86afe28bd6bded812c778c393282609f7c6881705da286e4227540abaf2
Deleted: sha256:933a91cf3e07efec429548c1f929a86681f287b1c136acfda511e4d78cf2d36f
Deleted: sha256:de2df8721ecf1ad4342cbe83c78ca766442de74b9226d819916bda9bab080e51
Deleted: sha256:8c0407624de9ebf3e8a736a92db8a9bebde9d7540793681935619a2752c8fd39
Deleted: sha256:c261b37c16bdd3e5819de9c0ec34ee249f9a7d8d02c62dbb21e04f1d152b2d0c
Deleted: sha256:39ee6027c4159747cda4a8082d718a7f347430401e5965546eb033a53f765e1a
Deleted: sha256:c7897f1cb91fd38087fae9a70b9a53fe4e786e6779f385eee982d42740b85518
Deleted: sha256:2460a1851a00ae19a937e36439acdc0c7caa04f01a9a9f0abb71d1bb5857491d
Deleted: sha256:fb1b5c80a981c2b8775b5b3829ecd0c486ab085836958cef127511f8475ff031
Deleted: sha256:749edfde10b3194e4589ced469a32c5539a736df4fd13369b335c49acbd3339c
Deleted: sha256:cb8199c5cdba2ff4d92b234033e96b1b15bcd7a965638baa0abcdcdf0248aa2c
Deleted: sha256:13e6a1c54675033806dd8aae5ba41263abdfbc71dba471977fa61043fa63ea11
Deleted: sha256:ca9b0f68335720814687efa4480e80f0f2c762904f2a1ce5874e283b3ff8f209
Deleted: sha256:a30fce8ef7fe65c73f82fd7bcf15a72251241c27e0d0b7e86c7791e8b4ac1a8e
Deleted: sha256:6701c8dfbd694d60f353bdfe0bfabc32aafe19bf9dd77f4423fce890e3642cab
Deleted: sha256:baa15cfba9120746a8bcec2f3e123c16c3d84d592d46ceffa79b5ea9a39dfe37
Deleted: sha256:5a886b39f9ac9dd2081e36362808a27804e7908914e85b8efc96a446efd404e0
Deleted: sha256:653a10c8ad529a39b30c2569a6b691fae2e5919e928af73a8e7118dcdabddfed
Deleted: sha256:5723db22982ea2ac9e05ac4d6755b4644ca227c4bcd4efbe06f9286af47bc2ca
Deleted: sha256:12aee1a4dbb7b4a031786bd942b315a0db0ac15cf7e9726e1c8ccb905cd5a177
Deleted: sha256:402fa760038ab8f060000dfce5af90b952bca86aadee37ec3f19ccd358836d90
Deleted: sha256:eafa94ce85a3f5ae2a3c8b8f03858b6f77a51383439f7a8d752b0212ed0446de
Deleted: sha256:2924cb04b68c05d7c9410cda1acf8a5ceb594bd6d543d3138bb27224930ba415
Deleted: sha256:df73aa9c0b092ed8f9cd63736ea85619e52dd9cc31d46781d5583b55fc31785d
Deleted: sha256:e65e54a602e581e9e080e1a066e2f38fb3567b9b6c2bc2993b230a1b801c8e4d
Deleted: sha256:aee3e9eed94bea7769bd3c8212a68bed0d9d01abbc75d81407c1cf3991c2ec7f
Deleted: sha256:33e9665997651c6b55e9312661db63bc23a84ef57843326f6cd5b12e5b58813c
Deleted: sha256:c82dddfc7d8a8b0458de189a4bf173c726133ce851f1a720dd60fb1638094e9f
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user xujyan@apple.com
Not sending mail to unregistered user yujie.jay@gmail.com


Build failed in Jenkins: Mesos-Buildbot » cmake,clang,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(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=clang,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4314/display/redirect?page=changes>

Changes:

[jpeach] Fixed default executor handling of nested container status.

------------------------------------------
[...truncated 31.92 MB...]
3: I1012 18:02:22.280199 23602 registrar.cpp:424] Successfully recovered registrar
3: I1012 18:02:22.280551 23607 master.cpp:1791] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1012 18:02:22.280642 23598 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: W1012 18:02:22.285789 17463 process.cpp:3194] Attempted to spawn already running process files@172.17.0.3:56720
3: I1012 18:02:22.286625 17463 containerizer.cpp:292] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1012 18:02:22.287060 17463 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1012 18:02:22.287173 17463 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1012 18:02:22.287204 17463 provisioner.cpp:255] Using default backend 'copy'
3: I1012 18:02:22.288880 17463 cluster.cpp:448] Creating default 'local' authorizer
3: I1012 18:02:22.290704 23608 slave.cpp:254] Mesos agent started on (830)@172.17.0.3:56720
3: W1012 18:02:22.291201 17463 process.cpp:3194] Attempted to spawn already running process version@172.17.0.3:56720
3: I1012 18:02:22.290737 23608 slave.cpp:255] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_p51uLp/store/appc" --authenticate_http_executors="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_p51uLp/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_p51uLp/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_secret_key="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_p51uLp/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_p51uLp/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_p51uLp/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_QvhZnk\/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_QvhZnk\/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_p51uLp" --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_9UwJ4m" --zk_session_timeout="10secs"
3: I1012 18:02:22.291290 23608 credentials.hpp:86] Loading credential for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_p51uLp/credential'
3: I1012 18:02:22.291496 23608 slave.cpp:287] Agent using credential for: test-principal
3: I1012 18:02:22.291519 23608 credentials.hpp:37] Loading credentials for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_p51uLp/http_credentials'
3: I1012 18:02:22.291867 23608 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1012 18:02:22.292049 23608 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1012 18:02:22.292102 17463 sched.cpp:232] Version: 1.5.0
3: I1012 18:02:22.292347 23608 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1012 18:02:22.292496 23608 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1012 18:02:22.292737 23605 sched.cpp:336] New master detected at master@172.17.0.3:56720
3: I1012 18:02:22.292744 23608 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1012 18:02:22.292873 23605 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1012 18:02:22.292879 23608 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1012 18:02:22.292896 23605 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.3:56720
3: I1012 18:02:22.293031 23605 sched.cpp:853] Will retry registration in 100.916625ms if necessary
3: I1012 18:02:22.293396 23594 master.cpp:2929] Received SUBSCRIBE call for framework 'default' at scheduler-1ca4c527-3296-4dbf-8ada-f065b5fa4468@172.17.0.3:56720
3: I1012 18:02:22.293586 23594 master.cpp:2263] Authorizing framework principal 'test-principal' to receive offers for roles '{ default-role }'
3: I1012 18:02:22.294191 23593 master.cpp:3009] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1012 18:02:22.294884 23593 sched.cpp:747] Framework registered with 06fd03c3-026b-4e3f-b274-e8176fa981af-0000
3: I1012 18:02:22.295075 23593 sched.cpp:761] Scheduler::registered took 31405ns
3: I1012 18:02:22.295178 23604 hierarchical.cpp:303] Added framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000
3: I1012 18:02:22.295409 23604 hierarchical.cpp:1943] No allocations performed
3: I1012 18:02:22.295447 23604 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 18:02:22.295502 23604 hierarchical.cpp:1486] Performed allocation for 0 agents in 144204ns
3: I1012 18:02:22.297718 23608 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_QvhZnk\/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_QvhZnk\/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 18:02:22.298265 23608 slave.cpp:593] Agent attributes: [  ]
3: I1012 18:02:22.298348 23608 slave.cpp:602] Agent hostname: da6d54d5f3ba
3: I1012 18:02:22.298498 23605 status_update_manager.cpp:177] Pausing sending status updates
3: I1012 18:02:22.300489 23600 state.cpp:64] Recovering state from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_9UwJ4m/meta'
3: I1012 18:02:22.300881 23599 status_update_manager.cpp:203] Recovering status update manager
3: I1012 18:02:22.301127 23606 containerizer.cpp:648] Recovering containerizer
3: I1012 18:02:22.302763 23594 provisioner.cpp:416] Provisioner recovery complete
3: I1012 18:02:22.303094 23600 slave.cpp:6310] Finished recovery
3: I1012 18:02:22.303740 23600 slave.cpp:6492] Querying resource estimator for oversubscribable resources
3: I1012 18:02:22.303997 23603 status_update_manager.cpp:177] Pausing sending status updates
3: I1012 18:02:22.304002 23593 slave.cpp:993] New master detected at master@172.17.0.3:56720
3: I1012 18:02:22.304054 23593 slave.cpp:1028] Detecting new master
3: I1012 18:02:22.304167 23593 slave.cpp:6506] Received oversubscribable resources {} from the resource estimator
3: I1012 18:02:22.304584 23596 slave.cpp:1055] Authenticating with master master@172.17.0.3:56720
3: I1012 18:02:22.304679 23596 slave.cpp:1064] Using default CRAM-MD5 authenticatee
3: I1012 18:02:22.304960 23601 authenticatee.cpp:121] Creating new client SASL connection
3: I1012 18:02:22.305088 23608 hierarchical.cpp:1943] No allocations performed
3: I1012 18:02:22.305119 23608 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 18:02:22.305160 23608 hierarchical.cpp:1486] Performed allocation for 0 agents in 124910ns
3: I1012 18:02:22.305493 23598 master.cpp:7936] Authenticating slave(830)@172.17.0.3:56720
3: I1012 18:02:22.305665 23597 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1499)@172.17.0.3:56720
3: I1012 18:02:22.306130 23594 authenticator.cpp:98] Creating new server SASL connection
3: I1012 18:02:22.306428 23599 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1012 18:02:22.306452 23599 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1012 18:02:22.306574 23599 authenticator.cpp:204] Received SASL authentication start
3: I1012 18:02:22.306632 23599 authenticator.cpp:326] Authentication requires more steps
3: I1012 18:02:22.306740 23599 authenticatee.cpp:259] Received SASL authentication step
3: I1012 18:02:22.306859 23603 authenticator.cpp:232] Received SASL authentication step
3: I1012 18:02:22.306891 23603 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'da6d54d5f3ba' server FQDN: 'da6d54d5f3ba' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1012 18:02:22.306906 23603 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1012 18:02:22.306952 23603 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1012 18:02:22.306979 23603 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'da6d54d5f3ba' server FQDN: 'da6d54d5f3ba' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1012 18:02:22.306991 23603 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1012 18:02:22.306999 23603 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1012 18:02:22.307016 23603 authenticator.cpp:318] Authentication success
3: I1012 18:02:22.307118 23600 authenticatee.cpp:299] Authentication success
3: I1012 18:02:22.307173 23593 master.cpp:7966] Successfully authenticated principal 'test-principal' at slave(830)@172.17.0.3:56720
3: I1012 18:02:22.307278 23604 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1499)@172.17.0.3:56720
3: I1012 18:02:22.309711 23605 slave.cpp:1147] Successfully authenticated with master master@172.17.0.3:56720
3: I1012 18:02:22.309980 23605 slave.cpp:1626] Will retry registration in 5.046945ms if necessary
3: I1012 18:02:22.310225 23601 master.cpp:5801] Received register agent message from slave(830)@172.17.0.3:56720 (da6d54d5f3ba)
3: I1012 18:02:22.310268 23601 master.cpp:3838] Authorizing agent with principal 'test-principal'
3: I1012 18:02:22.310837 23601 master.cpp:5861] Authorized registration of agent at slave(830)@172.17.0.3:56720 (da6d54d5f3ba)
3: I1012 18:02:22.310962 23601 master.cpp:5954] Registering agent at slave(830)@172.17.0.3:56720 (da6d54d5f3ba) with id 06fd03c3-026b-4e3f-b274-e8176fa981af-S0
3: I1012 18:02:22.311496 23597 registrar.cpp:495] Applied 1 operations in 152193ns; attempting to update the registry
3: I1012 18:02:22.312403 23597 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1012 18:02:22.312775 23600 master.cpp:6001] Admitted agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 at slave(830)@172.17.0.3:56720 (da6d54d5f3ba)
3: I1012 18:02:22.313980 23600 master.cpp:6032] Registered agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 at slave(830)@172.17.0.3:56720 (da6d54d5f3ba) 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_QvhZnk\/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_QvhZnk\/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 18:02:22.314860 23602 slave.cpp:1193] Registered with master master@172.17.0.3:56720; given agent ID 06fd03c3-026b-4e3f-b274-e8176fa981af-S0
3: I1012 18:02:22.315093 23606 status_update_manager.cpp:184] Resuming sending status updates
3: I1012 18:02:22.315521 23602 slave.cpp:1213] Checkpointing SlaveInfo to '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_9UwJ4m/meta/slaves/06fd03c3-026b-4e3f-b274-e8176fa981af-S0/slave.info'
3: I1012 18:02:22.315670 23600 hierarchical.cpp:593] Added agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 (da6d54d5f3ba) with cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk2]:2048; ports:[31000-32000] (allocated: {})
3: I1012 18:02:22.316290 23602 slave.cpp:1262] Forwarding total oversubscribed resources {}
3: I1012 18:02:22.316557 23602 slave.cpp:4966] Received ping from slave-observer(747)@172.17.0.3:56720
3: I1012 18:02:22.316581 23596 master.cpp:6817] Received update of agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 at slave(830)@172.17.0.3:56720 (da6d54d5f3ba) with total oversubscribed resources {}
3: I1012 18:02:22.316946 23596 master.cpp:6828] Ignoring update on agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 at slave(830)@172.17.0.3:56720 (da6d54d5f3ba) as it reports no changes
3: I1012 18:02:22.318467 23600 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 18:02:22.318514 23600 hierarchical.cpp:1486] Performed allocation for 1 agents in 2.628782ms
3: I1012 18:02:22.319285 23604 master.cpp:7766] Sending 1 offers to framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000 (default) at scheduler-1ca4c527-3296-4dbf-8ada-f065b5fa4468@172.17.0.3:56720
3: I1012 18:02:22.319849 23604 sched.cpp:917] Scheduler::resourceOffers took 98268ns
3: I1012 18:02:22.322144 23601 master.cpp:9389] Removing offer 06fd03c3-026b-4e3f-b274-e8176fa981af-O0
3: I1012 18:02:22.322293 23601 master.cpp:4196] Processing ACCEPT call for offers: [ 06fd03c3-026b-4e3f-b274-e8176fa981af-O0 ] on agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 at slave(830)@172.17.0.3:56720 (da6d54d5f3ba) for framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000 (default) at scheduler-1ca4c527-3296-4dbf-8ada-f065b5fa4468@172.17.0.3:56720
3: I1012 18:02:22.322510 23601 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_QvhZnk\/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 18:02:22.323803 23601 master.cpp:2348] Dropping CREATE offer operation from framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000 (default) at scheduler-1ca4c527-3296-4dbf-8ada-f065b5fa4468@172.17.0.3:56720: Not authorized to create persistent volumes as 'test-principal'
3: I1012 18:02:22.326058 23593 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_QvhZnk/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk2]:2048; ports:[31000-32000], allocated: {}) on agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 from framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000
3: I1012 18:02:22.328166 23606 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 18:02:22.328215 23606 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.400783ms
3: I1012 18:02:22.328986 23602 master.cpp:7766] Sending 1 offers to framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000 (default) at scheduler-1ca4c527-3296-4dbf-8ada-f065b5fa4468@172.17.0.3:56720
3: I1012 18:02:22.329627 23596 sched.cpp:917] Scheduler::resourceOffers took 166420ns
3: W1012 18:02:22.330289 17463 process.cpp:3194] Attempted to spawn already running process version@172.17.0.3:56720
3: I1012 18:02:22.330441 23604 master.cpp:5207] Processing DECLINE call for offers: [ 06fd03c3-026b-4e3f-b274-e8176fa981af-O1 ] for framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000 (default) at scheduler-1ca4c527-3296-4dbf-8ada-f065b5fa4468@172.17.0.3:56720
Errors while running CTest
3: I1012 18:02:22.330987 17463 sched.cpp:232] Version: 1.5.0
3: I1012 18:02:22.331930 23604 master.cpp:9389] Removing offer 06fd03c3-026b-4e3f-b274-e8176fa981af-O1
3: I1012 18:02:22.332214 23595 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_QvhZnk/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk2]:2048; ports:[31000-32000], allocated: {}) on agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 from framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000
3: I1012 18:02:22.332283 23600 master.cpp:3439] Processing SUPPRESS call for framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000 (default) at scheduler-1ca4c527-3296-4dbf-8ada-f065b5fa4468@172.17.0.3:56720
3: I1012 18:02:22.332381 23598 sched.cpp:336] New master detected at master@172.17.0.3:56720
3: I1012 18:02:22.332440 23599 hierarchical.cpp:1273] Suppressed offers for roles { default-role } of framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000
3: I1012 18:02:22.332520 23598 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1012 18:02:22.332533 23598 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.3:56720
3: I1012 18:02:22.332840 23603 master.cpp:2929] Received SUBSCRIBE call for framework 'creator-framework' at scheduler-ade9c0a9-2ad4-49e2-9af7-6bfa510fba8b@172.17.0.3:56720
3: I1012 18:02:22.332866 23603 master.cpp:2263] Authorizing framework principal 'creator-principal' to receive offers for roles '{ default-role }'
3: I1012 18:02:22.333487 23598 sched.cpp:853] Will retry registration in 601.631093ms if necessary
3: I1012 18:02:22.333559 23608 master.cpp:3009] Subscribing framework creator-framework with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1012 18:02:22.334070 23602 hierarchical.cpp:303] Added framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0001
3: I1012 18:02:22.334286 23608 sched.cpp:747] Framework registered with 06fd03c3-026b-4e3f-b274-e8176fa981af-0001
3: I1012 18:02:22.334328 23608 sched.cpp:761] Scheduler::registered took 28309ns
3: I1012 18:02:22.335491 23602 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 18:02:22.335522 23602 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.343261ms
3: I1012 18:02:22.336874 23604 master.cpp:7766] Sending 1 offers to framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0001 (creator-framework) at scheduler-ade9c0a9-2ad4-49e2-9af7-6bfa510fba8b@172.17.0.3:56720
3: I1012 18:02:22.337679 23601 sched.cpp:917] Scheduler::resourceOffers took 150859ns
3: I1012 18:02:22.338331 23607 hierarchical.cpp:1943] No allocations performed
3: I1012 18:02:22.338373 23607 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 18:02:22.338415 23607 hierarchical.cpp:1486] Performed allocation for 1 agents in 179613ns
3: I1012 18:02:22.340972 23600 master.cpp:9389] Removing offer 06fd03c3-026b-4e3f-b274-e8176fa981af-O2
3: I1012 18:02:22.341132 23600 master.cpp:4196] Processing ACCEPT call for offers: [ 06fd03c3-026b-4e3f-b274-e8176fa981af-O2 ] on agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 at slave(830)@172.17.0.3:56720 (da6d54d5f3ba) for framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0001 (creator-framework) at scheduler-ade9c0a9-2ad4-49e2-9af7-6bfa510fba8b@172.17.0.3:56720
3: I1012 18:02:22.341326 23600 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_QvhZnk\/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 18:02:22.343554 23600 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_QvhZnk\/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 06fd03c3-026b-4e3f-b274-e8176fa981af-0001 (creator-framework) at scheduler-ade9c0a9-2ad4-49e2-9af7-6bfa510fba8b@172.17.0.3:56720 to agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 at slave(830)@172.17.0.3:56720 (da6d54d5f3ba)
3: I1012 18:02:22.344377 23600 master.cpp:9335] Sending updated checkpointed resources disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk1,id1:path1]:2048 to agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 at slave(830)@172.17.0.3:56720 (da6d54d5f3ba)
3: I1012 18:02:22.345648 23606 slave.cpp:3519] Updated checkpointed resources from {} to disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk1,id1:path1]:2048
3: I1012 18:02:22.349248 23596 hierarchical.cpp:887] Updated allocation of framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0001 on agent 06fd03c3-026b-4e3f-b274-e8176fa981af-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_QvhZnk/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/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_QvhZnk/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk1,id1:path1]:2048
3: I1012 18:02:22.351083 23596 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_QvhZnk/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk1,id1:path1]:2048, allocated: {}) on agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 from framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0001
3: I1012 18:02:22.353068 23608 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 18:02:22.353183 23608 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.583956ms
3: I1012 18:02:22.353955 23602 master.cpp:7766] Sending 1 offers to framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0001 (creator-framework) at scheduler-ade9c0a9-2ad4-49e2-9af7-6bfa510fba8b@172.17.0.3:56720
3: I1012 18:02:22.354882 23604 sched.cpp:917] Scheduler::resourceOffers took 193375ns
3: I1012 18:02:22.355597 23597 master.cpp:5207] Processing DECLINE call for offers: [ 06fd03c3-026b-4e3f-b274-e8176fa981af-O3 ] for framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0001 (creator-framework) at scheduler-ade9c0a9-2ad4-49e2-9af7-6bfa510fba8b@172.17.0.3:56720
3: I1012 18:02:22.356736 23597 master.cpp:9389] Removing offer 06fd03c3-026b-4e3f-b274-e8176fa981af-O3
3: I1012 18:02:22.356951 23597 master.cpp:3439] Processing SUPPRESS call for framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0001 (creator-framework) at scheduler-ade9c0a9-2ad4-49e2-9af7-6bfa510fba8b@172.17.0.3:56720
3: I1012 18:02:22.357651 23595 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_QvhZnk/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk1,id1:path1]:2048, allocated: {}) on agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 from framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0001
3: I1012 18:02:22.357820 23595 hierarchical.cpp:1273] Suppressed offers for roles { default-role } of framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0001
3: I1012 18:02:22.358173 23593 master.cpp:5312] Processing REVIVE call for framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000 (default) at scheduler-1ca4c527-3296-4dbf-8ada-f065b5fa4468@172.17.0.3:56720
3: I1012 18:02:22.358366 23599 hierarchical.cpp:1308] Revived offers for roles { default-role } of framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000
3: I1012 18:02:22.361084 23599 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 18:02:22.361132 23599 hierarchical.cpp:1486] Performed allocation for 1 agents in 2.589019ms
3: I1012 18:02:22.362373 23603 master.cpp:7766] Sending 1 offers to framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000 (default) at scheduler-1ca4c527-3296-4dbf-8ada-f065b5fa4468@172.17.0.3:56720
3: I1012 18:02:22.363176 23603 sched.cpp:917] Scheduler::resourceOffers took 168490ns
3: I1012 18:02:22.365658 23600 master.cpp:9389] Removing offer 06fd03c3-026b-4e3f-b274-e8176fa981af-O4
3: I1012 18:02:22.365818 23600 master.cpp:4196] Processing ACCEPT call for offers: [ 06fd03c3-026b-4e3f-b274-e8176fa981af-O4 ] on agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 at slave(830)@172.17.0.3:56720 (da6d54d5f3ba) for framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000 (default) at scheduler-1ca4c527-3296-4dbf-8ada-f065b5fa4468@172.17.0.3:56720
3: I1012 18:02:22.366027 23600 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_QvhZnk\/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 18:02:22.367516 23600 master.cpp:2348] Dropping DESTROY offer operation from framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000 (default) at scheduler-1ca4c527-3296-4dbf-8ada-f065b5fa4468@172.17.0.3:56720: Not authorized to destroy persistent volumes as 'test-principal'
3: I1012 18:02:22.368958 23602 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_QvhZnk/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk1,id1:path1]:2048, allocated: {}) on agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 from framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000
3: I1012 18:02:22.371640 23601 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 18:02:22.371798 23601 hierarchical.cpp:1486] Performed allocation for 1 agents in 2.160209ms
3: I1012 18:02:22.372385 23597 master.cpp:7766] Sending 1 offers to framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000 (default) at scheduler-1ca4c527-3296-4dbf-8ada-f065b5fa4468@172.17.0.3:56720
3: I1012 18:02:22.372984 23595 sched.cpp:917] Scheduler::resourceOffers took 126493ns
3: I1012 18:02:22.373266 17463 sched.cpp:2005] Asked to stop the driver
3: I1012 18:02:22.373380 23607 sched.cpp:1187] Stopping framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000
3: I1012 18:02:22.373601 23593 master.cpp:8447] Processing TEARDOWN call for framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000 (default) at scheduler-1ca4c527-3296-4dbf-8ada-f065b5fa4468@172.17.0.3:56720
3: I1012 18:02:22.373625 23593 master.cpp:8459] Removing framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000 (default) at scheduler-1ca4c527-3296-4dbf-8ada-f065b5fa4468@172.17.0.3:56720
3: I1012 18:02:22.373636 23593 master.cpp:3299] Deactivating framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000 (default) at scheduler-1ca4c527-3296-4dbf-8ada-f065b5fa4468@172.17.0.3:56720
3: I1012 18:02:22.373786 23594 hierarchical.cpp:412] Deactivated framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000
3: I1012 18:02:22.373847 17463 sched.cpp:2005] Asked to stop the driver
3: I1012 18:02:22.374007 23605 sched.cpp:1187] Stopping framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0001
3: I1012 18:02:22.374615 23593 master.cpp:9389] Removing offer 06fd03c3-026b-4e3f-b274-e8176fa981af-O5
3: I1012 18:02:22.374872 23602 slave.cpp:3211] Asked to shut down framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000 by master@172.17.0.3:56720
3: I1012 18:02:22.374902 23602 slave.cpp:3226] Cannot shut down unknown framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000
3: I1012 18:02:22.375108 23593 master.cpp:8447] Processing TEARDOWN call for framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0001 (creator-framework) at scheduler-ade9c0a9-2ad4-49e2-9af7-6bfa510fba8b@172.17.0.3:56720
3: I1012 18:02:22.375129 23593 master.cpp:8459] Removing framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0001 (creator-framework) at scheduler-ade9c0a9-2ad4-49e2-9af7-6bfa510fba8b@172.17.0.3:56720
3: I1012 18:02:22.375138 23593 master.cpp:3299] Deactivating framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0001 (creator-framework) at scheduler-ade9c0a9-2ad4-49e2-9af7-6bfa510fba8b@172.17.0.3:56720
3: I1012 18:02:22.375294 23595 slave.cpp:3211] Asked to shut down framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0001 by master@172.17.0.3:56720
3: I1012 18:02:22.375319 23595 slave.cpp:3226] Cannot shut down unknown framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0001
3: I1012 18:02:22.375399 23606 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_QvhZnk/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_QvhZnk/disk1,id1:path1]:2048, allocated: {}) on agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 from framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000
3: I1012 18:02:22.375600 23606 hierarchical.cpp:355] Removed framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0000
3: I1012 18:02:22.375743 23606 hierarchical.cpp:412] Deactivated framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0001
3: I1012 18:02:22.375984 23606 hierarchical.cpp:355] Removed framework 06fd03c3-026b-4e3f-b274-e8176fa981af-0001
3: I1012 18:02:22.376739 17463 slave.cpp:869] Agent terminating
3: I1012 18:02:22.376988 23604 master.cpp:1303] Agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 at slave(830)@172.17.0.3:56720 (da6d54d5f3ba) disconnected
3: I1012 18:02:22.377023 23604 master.cpp:3336] Disconnecting agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 at slave(830)@172.17.0.3:56720 (da6d54d5f3ba)
3: I1012 18:02:22.377106 23604 master.cpp:3355] Deactivating agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 at slave(830)@172.17.0.3:56720 (da6d54d5f3ba)
3: I1012 18:02:22.377267 23603 hierarchical.cpp:690] Agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0 deactivated
3: I1012 18:02:22.384117 17463 master.cpp:1145] Master terminating
3: I1012 18:02:22.385030 23602 hierarchical.cpp:626] Removed agent 06fd03c3-026b-4e3f-b274-e8176fa981af-S0
3: [       OK ] DiskResource/PersistentVolumeTest.BadACLDropCreateAndDestroy/1 (122 ms)
3: [----------] 34 tests from DiskResource/PersistentVolumeTest (11486 ms total)
3: 
3: [----------] Global test environment tear-down
3: [==========] 1656 tests from 180 test cases ran. (448964 ms total)
3: [  PASSED  ] 1654 tests.
3: [  FAILED  ] 2 tests, listed below:
3: [  FAILED  ] ExecutorAuthorizationTest.RunTaskGroup
3: [  FAILED  ] SlaveTest.RestartSlaveRequireExecutorAuthentication
3: 
3:  2 FAILED TESTS
3:   YOU HAVE 21 DISABLED TESTS
3: 
3: I1012 18:02:22.472468 23609 process.cpp:1068] Failed to accept socket: future discarded
3/3 Test #3: MesosTests .......................***Failed  453.55 sec

67% tests passed, 1 tests failed out of 3

Total Test time (real) = 491.91 sec

The following tests FAILED:
	  3 - MesosTests (Failed)
make[3]: Leaving directory `/mesos/build'
make[2]: Leaving directory `/mesos/build'
make[1]: Leaving directory `/mesos/build'
make[3]: *** [CMakeFiles/check] Error 8
make[2]: *** [CMakeFiles/check.dir/all] Error 2
make[1]: *** [CMakeFiles/check.dir/rule] Error 2
make: *** [check] Error 2
+ docker rmi mesos-1507828999-15795
Untagged: mesos-1507828999-15795:latest
Deleted: sha256:43160c12b4b751ae1396dc1234af500201383cf4910800182cdec723597f807c
Deleted: sha256:1fb9623e6d533f19b1ff93b857793f9e3f9c9ae7e0e12830d2134f2549f57946
Deleted: sha256:78a22beab0696831af1ce51a6ec32bbfb545e6ebaeec9c7b66e7f5cafc36c444
Deleted: sha256:a2f0cba6025dbf2ef56859a78113a1c39c9585d0114982e580e28706fdac923e
Deleted: sha256:4056de146a1c45d9476b325ca54fa338dff9b96e5ca519aba1e0c1e5745195aa
Deleted: sha256:2e41c5984613a907dadde6b42815626df2a4559ec0eb83cd91e80f014ba21a95
Deleted: sha256:9ceeb93231ddf1f6736f7c4ec39514a978454debd1c9f878184ebc73e057f34e
Deleted: sha256:67df418166754aedd279ab2f7a639811b6c1fc3715655fe54ed54a6177d7f2dd
Deleted: sha256:acc31248000546395a7018dd5dc23709e6f4c83410169d856d80aba2d8ca96de
Deleted: sha256:290ba8a9c22a32b22ff37ee89ee640b7c7e8c881b960844173309fa84f8197ed
Deleted: sha256:5a1c4f3d7a4fa92cc5a49c4eaa0260b77f887fbeed451ca3bfbd8112e8d33799
Deleted: sha256:050473b94ee1107e0938df5aea9137a71a86fc045d2692efe12f48bdd38f5b32
Deleted: sha256:6b3191a43395ac3da677834abf0ee80ba4e865903fabd372456604b1877dfb1c
Deleted: sha256:f16dac1f3bcc4e853cf40a554447fffe78665f0541a022e9d44cda19f99ff391
Deleted: sha256:99c993a1968637818010e23d11135b2867084b5f8443096a84e3d41da8503008
Deleted: sha256:df31f56ae5ad8d75d7d3e556227d2b26dfc3bf0c9dd4640e6164fc4abb88656e
Deleted: sha256:7287482641319de901127e39c2308fba077cb7c3f84fe2e8252dd9e3a57fef74
Deleted: sha256:43281ba4a387f9e8db9cfcab0ac89c3c3342847100c22fb86c40995b0339b727
Deleted: sha256:3f3f6d9dc8638807648b4edd0f745110b9f242b767d5fb2723fb87de77cb086c
Deleted: sha256:4a017e9be5f19b6ff55b02de1bfc332829106af42a0cef0ddd3b2c588e7b1887
Deleted: sha256:668b07ba4d602f649e4c927782666019c059a0e3697f26f50a978576929851b6
Deleted: sha256:1646528d6d1b863981adc58f668d327f6f03c95b8092afa3d55f8be39facd644
Deleted: sha256:59cd2dc9e0d37228ccb8707e479bbff2886ad211446f387812e344ed131a3426
Deleted: sha256:19b8b817336bdd7af3cd4054fdf6a0b55805b4d0515a69e382d6c373d5504376
Deleted: sha256:72bb841c5c82c437985edf8cd0e26f97acf586c9384b6d140512dc952e65df17
Deleted: sha256:7888e0d26f98342f4cbbc9233f17f1aeabd0e1019eac6e866bd3039f80f864fb
Deleted: sha256:9e1d1563773402d98bc7cc036cacef9c48db30a176e30ebcf5e0093c8feab27f
Deleted: sha256:9d95770fc94f1a02613898f4c2bc38625922bb3708d1c67d87e64e1a3605a5c3
Build step 'Execute shell' marked build as failure


Build failed in Jenkins: Mesos-Buildbot » cmake,clang,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(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=clang,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/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 31.88 MB...]
3: I1012 16:58:14.031473 23596 registrar.cpp:424] Successfully recovered registrar
3: I1012 16:58:14.031868 23592 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: I1012 16:58:14.031841 23593 master.cpp:1791] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: W1012 16:58:14.037005 17461 process.cpp:3194] Attempted to spawn already running process files@172.17.0.2:60093
3: I1012 16:58:14.037850 17461 containerizer.cpp:292] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1012 16:58:14.038301 17461 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1012 16:58:14.038414 17461 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1012 16:58:14.038444 17461 provisioner.cpp:255] Using default backend 'copy'
3: I1012 16:58:14.040143 17461 cluster.cpp:448] Creating default 'local' authorizer
3: I1012 16:58:14.042062 23604 slave.cpp:254] Mesos agent started on (830)@172.17.0.2:60093
3: I1012 16:58:14.042101 23604 slave.cpp:255] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_a9kH3D/store/appc" --authenticate_http_executors="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_a9kH3D/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_a9kH3D/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_secret_key="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_a9kH3D/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_a9kH3D/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_a9kH3D/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_r4c3PL\/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_r4c3PL\/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_a9kH3D" --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_7wqRWc" --zk_session_timeout="10secs"
3: I1012 16:58:14.042582 23604 credentials.hpp:86] Loading credential for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_a9kH3D/credential'
3: W1012 16:58:14.042606 17461 process.cpp:3194] Attempted to spawn already running process version@172.17.0.2:60093
3: I1012 16:58:14.042805 23604 slave.cpp:287] Agent using credential for: test-principal
3: I1012 16:58:14.042826 23604 credentials.hpp:37] Loading credentials for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_a9kH3D/http_credentials'
3: I1012 16:58:14.043185 23604 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1012 16:58:14.043344 23604 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1012 16:58:14.043483 17461 sched.cpp:232] Version: 1.5.0
3: I1012 16:58:14.043644 23604 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1012 16:58:14.043766 23604 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1012 16:58:14.043998 23604 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1012 16:58:14.044262 23604 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1012 16:58:14.044509 23602 sched.cpp:336] New master detected at master@172.17.0.2:60093
3: I1012 16:58:14.044682 23602 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1012 16:58:14.044701 23602 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.2:60093
3: I1012 16:58:14.044975 23602 sched.cpp:853] Will retry registration in 362.466146ms if necessary
3: I1012 16:58:14.045150 23590 master.cpp:2929] Received SUBSCRIBE call for framework 'default' at scheduler-e25bd710-8e26-450d-81e6-b3cf9acd163b@172.17.0.2:60093
3: I1012 16:58:14.045173 23590 master.cpp:2263] Authorizing framework principal 'test-principal' to receive offers for roles '{ default-role }'
3: I1012 16:58:14.045755 23595 master.cpp:3009] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1012 16:58:14.046555 23592 hierarchical.cpp:303] Added framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000
3: I1012 16:58:14.046609 23595 sched.cpp:747] Framework registered with 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000
3: I1012 16:58:14.046929 23595 sched.cpp:761] Scheduler::registered took 29871ns
3: I1012 16:58:14.047130 23592 hierarchical.cpp:1943] No allocations performed
3: I1012 16:58:14.047168 23592 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 16:58:14.047322 23592 hierarchical.cpp:1486] Performed allocation for 0 agents in 286435ns
3: I1012 16:58:14.049621 23604 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_r4c3PL\/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_r4c3PL\/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:58:14.050179 23604 slave.cpp:593] Agent attributes: [  ]
3: I1012 16:58:14.050192 23604 slave.cpp:602] Agent hostname: 3a9b6161ff79
3: I1012 16:58:14.050384 23599 status_update_manager.cpp:177] Pausing sending status updates
3: I1012 16:58:14.052093 23602 state.cpp:64] Recovering state from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_7wqRWc/meta'
3: I1012 16:58:14.052446 23602 status_update_manager.cpp:203] Recovering status update manager
3: I1012 16:58:14.052723 23594 containerizer.cpp:648] Recovering containerizer
3: I1012 16:58:14.054121 23596 provisioner.cpp:416] Provisioner recovery complete
3: I1012 16:58:14.054416 23602 slave.cpp:6310] Finished recovery
3: I1012 16:58:14.055018 23602 slave.cpp:6492] Querying resource estimator for oversubscribable resources
3: I1012 16:58:14.055346 23591 status_update_manager.cpp:177] Pausing sending status updates
3: I1012 16:58:14.055354 23602 slave.cpp:993] New master detected at master@172.17.0.2:60093
3: I1012 16:58:14.055410 23602 slave.cpp:1028] Detecting new master
3: I1012 16:58:14.055495 23602 slave.cpp:6506] Received oversubscribable resources {} from the resource estimator
3: I1012 16:58:14.055908 23603 slave.cpp:1055] Authenticating with master master@172.17.0.2:60093
3: I1012 16:58:14.055981 23603 slave.cpp:1064] Using default CRAM-MD5 authenticatee
3: I1012 16:58:14.056445 23601 hierarchical.cpp:1943] No allocations performed
3: I1012 16:58:14.056449 23598 authenticatee.cpp:121] Creating new client SASL connection
3: I1012 16:58:14.056489 23601 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 16:58:14.056519 23601 hierarchical.cpp:1486] Performed allocation for 0 agents in 131536ns
3: I1012 16:58:14.056776 23604 master.cpp:7936] Authenticating slave(830)@172.17.0.2:60093
3: I1012 16:58:14.056886 23590 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1498)@172.17.0.2:60093
3: I1012 16:58:14.057103 23596 authenticator.cpp:98] Creating new server SASL connection
3: I1012 16:58:14.057318 23597 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1012 16:58:14.057344 23597 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1012 16:58:14.057454 23593 authenticator.cpp:204] Received SASL authentication start
3: I1012 16:58:14.057562 23593 authenticator.cpp:326] Authentication requires more steps
3: I1012 16:58:14.057659 23593 authenticatee.cpp:259] Received SASL authentication step
3: I1012 16:58:14.057773 23591 authenticator.cpp:232] Received SASL authentication step
3: I1012 16:58:14.057807 23591 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3a9b6161ff79' server FQDN: '3a9b6161ff79' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1012 16:58:14.057826 23591 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1012 16:58:14.057867 23591 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1012 16:58:14.057890 23591 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3a9b6161ff79' server FQDN: '3a9b6161ff79' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1012 16:58:14.057904 23591 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1012 16:58:14.057911 23591 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1012 16:58:14.057929 23591 authenticator.cpp:318] Authentication success
3: I1012 16:58:14.058003 23602 authenticatee.cpp:299] Authentication success
3: I1012 16:58:14.058121 23600 master.cpp:7966] Successfully authenticated principal 'test-principal' at slave(830)@172.17.0.2:60093
3: I1012 16:58:14.058164 23603 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1498)@172.17.0.2:60093
3: I1012 16:58:14.058256 23589 slave.cpp:1147] Successfully authenticated with master master@172.17.0.2:60093
3: I1012 16:58:14.058552 23589 slave.cpp:1626] Will retry registration in 5.558638ms if necessary
3: I1012 16:58:14.058778 23590 master.cpp:5801] Received register agent message from slave(830)@172.17.0.2:60093 (3a9b6161ff79)
3: I1012 16:58:14.058815 23590 master.cpp:3838] Authorizing agent with principal 'test-principal'
3: I1012 16:58:14.059312 23590 master.cpp:5861] Authorized registration of agent at slave(830)@172.17.0.2:60093 (3a9b6161ff79)
3: I1012 16:58:14.059434 23590 master.cpp:5954] Registering agent at slave(830)@172.17.0.2:60093 (3a9b6161ff79) with id 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0
3: I1012 16:58:14.059772 23596 registrar.cpp:495] Applied 1 operations in 74733ns; attempting to update the registry
3: I1012 16:58:14.060333 23596 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1012 16:58:14.060557 23594 master.cpp:6001] Admitted agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 at slave(830)@172.17.0.2:60093 (3a9b6161ff79)
3: I1012 16:58:14.061187 23600 slave.cpp:4966] Received ping from slave-observer(746)@172.17.0.2:60093
3: I1012 16:58:14.061492 23600 slave.cpp:1193] Registered with master master@172.17.0.2:60093; given agent ID 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0
3: I1012 16:58:14.061769 23601 hierarchical.cpp:593] Added agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 (3a9b6161ff79) with cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk2]:2048; ports:[31000-32000] (allocated: {})
3: I1012 16:58:14.061300 23594 master.cpp:6032] Registered agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 at slave(830)@172.17.0.2:60093 (3a9b6161ff79) 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_r4c3PL\/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_r4c3PL\/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:58:14.062083 23600 slave.cpp:1213] Checkpointing SlaveInfo to '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_7wqRWc/meta/slaves/2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0/slave.info'
3: I1012 16:58:14.062018 23595 status_update_manager.cpp:184] Resuming sending status updates
3: I1012 16:58:14.062682 23600 slave.cpp:1262] Forwarding total oversubscribed resources {}
3: I1012 16:58:14.062880 23598 master.cpp:6817] Received update of agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 at slave(830)@172.17.0.2:60093 (3a9b6161ff79) with total oversubscribed resources {}
3: I1012 16:58:14.063132 23598 master.cpp:6828] Ignoring update on agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 at slave(830)@172.17.0.2:60093 (3a9b6161ff79) as it reports no changes
3: I1012 16:58:14.063318 23601 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 16:58:14.063360 23601 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.423808ms
3: I1012 16:58:14.064098 23603 master.cpp:7766] Sending 1 offers to framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000 (default) at scheduler-e25bd710-8e26-450d-81e6-b3cf9acd163b@172.17.0.2:60093
3: I1012 16:58:14.064653 23589 sched.cpp:917] Scheduler::resourceOffers took 105210ns
3: I1012 16:58:14.066941 23590 master.cpp:9389] Removing offer 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-O0
3: I1012 16:58:14.067101 23590 master.cpp:4196] Processing ACCEPT call for offers: [ 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-O0 ] on agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 at slave(830)@172.17.0.2:60093 (3a9b6161ff79) for framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000 (default) at scheduler-e25bd710-8e26-450d-81e6-b3cf9acd163b@172.17.0.2:60093
3: I1012 16:58:14.067296 23590 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_r4c3PL\/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:58:14.068528 23590 master.cpp:2348] Dropping CREATE offer operation from framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000 (default) at scheduler-e25bd710-8e26-450d-81e6-b3cf9acd163b@172.17.0.2:60093: Not authorized to create persistent volumes as 'test-principal'
3: I1012 16:58:14.069865 23592 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_r4c3PL/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk2]:2048; ports:[31000-32000], allocated: {}) on agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 from framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000
3: I1012 16:58:14.072026 23594 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 16:58:14.072088 23594 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.503412ms
3: I1012 16:58:14.072887 23595 master.cpp:7766] Sending 1 offers to framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000 (default) at scheduler-e25bd710-8e26-450d-81e6-b3cf9acd163b@172.17.0.2:60093
3: I1012 16:58:14.073596 23600 sched.cpp:917] Scheduler::resourceOffers took 139256ns
3: W1012 16:58:14.074290 17461 process.cpp:3194] Attempted to spawn already running process version@172.17.0.2:60093
3: I1012 16:58:14.074316 23601 master.cpp:5207] Processing DECLINE call for offers: [ 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-O1 ] for framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000 (default) at scheduler-e25bd710-8e26-450d-81e6-b3cf9acd163b@172.17.0.2:60093
3: I1012 16:58:14.075119 17461 sched.cpp:232] Version: 1.5.0
3: I1012 16:58:14.075371 23601 master.cpp:9389] Removing offer 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-O1
3: I1012 16:58:14.075531 23601 master.cpp:3439] Processing SUPPRESS call for framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000 (default) at scheduler-e25bd710-8e26-450d-81e6-b3cf9acd163b@172.17.0.2:60093
3: I1012 16:58:14.076098 23602 sched.cpp:336] New master detected at master@172.17.0.2:60093
3: I1012 16:58:14.076284 23602 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1012 16:58:14.076252 23589 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_r4c3PL/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk2]:2048; ports:[31000-32000], allocated: {}) on agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 from framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000
3: I1012 16:58:14.076524 23589 hierarchical.cpp:1273] Suppressed offers for roles { default-role } of framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000
3: I1012 16:58:14.076362 23602 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.2:60093
3: I1012 16:58:14.076683 23602 sched.cpp:853] Will retry registration in 407.67009ms if necessary
3: I1012 16:58:14.076838 23599 master.cpp:2929] Received SUBSCRIBE call for framework 'creator-framework' at scheduler-b16030f3-946d-4d8d-a3ad-dd251e7b09b0@172.17.0.2:60093
3: I1012 16:58:14.076860 23599 master.cpp:2263] Authorizing framework principal 'creator-principal' to receive offers for roles '{ default-role }'
3: I1012 16:58:14.077390 23590 master.cpp:3009] Subscribing framework creator-framework with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1012 16:58:14.077886 23591 hierarchical.cpp:303] Added framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001
3: I1012 16:58:14.078024 23590 sched.cpp:747] Framework registered with 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001
3: I1012 16:58:14.078091 23590 sched.cpp:761] Scheduler::registered took 52135ns
3: I1012 16:58:14.079421 23591 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 16:58:14.079464 23591 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.358581ms
3: I1012 16:58:14.080381 23600 master.cpp:7766] Sending 1 offers to framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001 (creator-framework) at scheduler-b16030f3-946d-4d8d-a3ad-dd251e7b09b0@172.17.0.2:60093
3: I1012 16:58:14.081059 23598 sched.cpp:917] Scheduler::resourceOffers took 111653ns
3: I1012 16:58:14.081691 23593 hierarchical.cpp:1943] No allocations performed
3: I1012 16:58:14.081732 23593 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 16:58:14.081766 23593 hierarchical.cpp:1486] Performed allocation for 1 agents in 187533ns
3: I1012 16:58:14.083570 23597 master.cpp:9389] Removing offer 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-O2
3: I1012 16:58:14.083714 23597 master.cpp:4196] Processing ACCEPT call for offers: [ 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-O2 ] on agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 at slave(830)@172.17.0.2:60093 (3a9b6161ff79) for framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001 (creator-framework) at scheduler-b16030f3-946d-4d8d-a3ad-dd251e7b09b0@172.17.0.2:60093
3: I1012 16:58:14.083890 23597 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_r4c3PL\/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:58:14.085552 23597 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_r4c3PL\/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 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001 (creator-framework) at scheduler-b16030f3-946d-4d8d-a3ad-dd251e7b09b0@172.17.0.2:60093 to agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 at slave(830)@172.17.0.2:60093 (3a9b6161ff79)
3: I1012 16:58:14.086102 23597 master.cpp:9335] Sending updated checkpointed resources disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk1,id1:path1]:2048 to agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 at slave(830)@172.17.0.2:60093 (3a9b6161ff79)
3: I1012 16:58:14.087581 23595 slave.cpp:3519] Updated checkpointed resources from {} to disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk1,id1:path1]:2048
3: I1012 16:58:14.089740 23594 hierarchical.cpp:887] Updated allocation of framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001 on agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-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_r4c3PL/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/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_r4c3PL/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk1,id1:path1]:2048
3: I1012 16:58:14.091131 23594 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_r4c3PL/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk1,id1:path1]:2048, allocated: {}) on agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 from framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001
3: I1012 16:58:14.093050 23591 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 16:58:14.093156 23591 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.504822ms
3: I1012 16:58:14.093938 23600 master.cpp:7766] Sending 1 offers to framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001 (creator-framework) at scheduler-b16030f3-946d-4d8d-a3ad-dd251e7b09b0@172.17.0.2:60093
3: I1012 16:58:14.094794 23598 sched.cpp:917] Scheduler::resourceOffers took 137747ns
3: I1012 16:58:14.095588 23603 master.cpp:5207] Processing DECLINE call for offers: [ 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-O3 ] for framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001 (creator-framework) at scheduler-b16030f3-946d-4d8d-a3ad-dd251e7b09b0@172.17.0.2:60093
3: I1012 16:58:14.096599 23603 master.cpp:9389] Removing offer 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-O3
3: I1012 16:58:14.096748 23603 master.cpp:3439] Processing SUPPRESS call for framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001 (creator-framework) at scheduler-b16030f3-946d-4d8d-a3ad-dd251e7b09b0@172.17.0.2:60093
3: I1012 16:58:14.097762 23593 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_r4c3PL/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk1,id1:path1]:2048, allocated: {}) on agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 from framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001
3: I1012 16:58:14.097975 23593 hierarchical.cpp:1273] Suppressed offers for roles { default-role } of framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001
3: I1012 16:58:14.098441 23589 master.cpp:5312] Processing REVIVE call for framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000 (default) at scheduler-e25bd710-8e26-450d-81e6-b3cf9acd163b@172.17.0.2:60093
3: I1012 16:58:14.098682 23589 hierarchical.cpp:1308] Revived offers for roles { default-role } of framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000
3: I1012 16:58:14.100224 23589 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 16:58:14.100302 23589 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.391449ms
3: I1012 16:58:14.101138 23599 master.cpp:7766] Sending 1 offers to framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000 (default) at scheduler-e25bd710-8e26-450d-81e6-b3cf9acd163b@172.17.0.2:60093
3: I1012 16:58:14.101802 23596 sched.cpp:917] Scheduler::resourceOffers took 107432ns
3: I1012 16:58:14.103320 23597 master.cpp:9389] Removing offer 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-O4
3: I1012 16:58:14.103543 23597 master.cpp:4196] Processing ACCEPT call for offers: [ 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-O4 ] on agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 at slave(830)@172.17.0.2:60093 (3a9b6161ff79) for framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000 (default) at scheduler-e25bd710-8e26-450d-81e6-b3cf9acd163b@172.17.0.2:60093
3: I1012 16:58:14.103786 23597 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_r4c3PL\/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:58:14.104998 23597 master.cpp:2348] Dropping DESTROY offer operation from framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000 (default) at scheduler-e25bd710-8e26-450d-81e6-b3cf9acd163b@172.17.0.2:60093: Not authorized to destroy persistent volumes as 'test-principal'
3: I1012 16:58:14.106493 23601 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_r4c3PL/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk1,id1:path1]:2048, allocated: {}) on agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 from framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000
3: I1012 16:58:14.109045 23593 hierarchical.cpp:2033] No inverse offers to send out!
3: I1012 16:58:14.109128 23593 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.989918ms
3: I1012 16:58:14.109881 23604 master.cpp:7766] Sending 1 offers to framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000 (default) at scheduler-e25bd710-8e26-450d-81e6-b3cf9acd163b@172.17.0.2:60093
3: I1012 16:58:14.110504 23602 sched.cpp:917] Scheduler::resourceOffers took 107985ns
3: I1012 16:58:14.110811 17461 sched.cpp:2005] Asked to stop the driver
3: I1012 16:58:14.110939 23589 sched.cpp:1187] Stopping framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000
3: I1012 16:58:14.111207 23599 master.cpp:8447] Processing TEARDOWN call for framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000 (default) at scheduler-e25bd710-8e26-450d-81e6-b3cf9acd163b@172.17.0.2:60093
3: I1012 16:58:14.111234 23599 master.cpp:8459] Removing framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000 (default) at scheduler-e25bd710-8e26-450d-81e6-b3cf9acd163b@172.17.0.2:60093
3: I1012 16:58:14.111253 23599 master.cpp:3299] Deactivating framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000 (default) at scheduler-e25bd710-8e26-450d-81e6-b3cf9acd163b@172.17.0.2:60093
3: I1012 16:58:14.111372 23589 hierarchical.cpp:412] Deactivated framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000
3: I1012 16:58:14.111382 17461 sched.cpp:2005] Asked to stop the driver
3: I1012 16:58:14.111486 23590 sched.cpp:1187] Stopping framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001
3: I1012 16:58:14.112179 23599 master.cpp:9389] Removing offer 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-O5
3: I1012 16:58:14.112426 23603 slave.cpp:3211] Asked to shut down framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000 by master@172.17.0.2:60093
3: I1012 16:58:14.112545 23603 slave.cpp:3226] Cannot shut down unknown framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000
3: I1012 16:58:14.112642 23599 master.cpp:8447] Processing TEARDOWN call for framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001 (creator-framework) at scheduler-b16030f3-946d-4d8d-a3ad-dd251e7b09b0@172.17.0.2:60093
3: I1012 16:58:14.112663 23599 master.cpp:8459] Removing framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001 (creator-framework) at scheduler-b16030f3-946d-4d8d-a3ad-dd251e7b09b0@172.17.0.2:60093
3: I1012 16:58:14.112673 23599 master.cpp:3299] Deactivating framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001 (creator-framework) at scheduler-b16030f3-946d-4d8d-a3ad-dd251e7b09b0@172.17.0.2:60093
3: I1012 16:58:14.112841 23589 slave.cpp:3211] Asked to shut down framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001 by master@172.17.0.2:60093
3: I1012 16:58:14.112911 23589 slave.cpp:3226] Cannot shut down unknown framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001
3: I1012 16:58:14.113656 23600 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_r4c3PL/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_r4c3PL/disk1,id1:path1]:2048, allocated: {}) on agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 from framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000
3: I1012 16:58:14.113929 23600 hierarchical.cpp:355] Removed framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0000
3: I1012 16:58:14.113998 23600 hierarchical.cpp:412] Deactivated framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001
3: I1012 16:58:14.114258 23600 hierarchical.cpp:355] Removed framework 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-0001
3: I1012 16:58:14.114502 17461 slave.cpp:869] Agent terminating
3: I1012 16:58:14.114652 23602 master.cpp:1303] Agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 at slave(830)@172.17.0.2:60093 (3a9b6161ff79) disconnected
3: I1012 16:58:14.114675 23602 master.cpp:3336] Disconnecting agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 at slave(830)@172.17.0.2:60093 (3a9b6161ff79)
3: I1012 16:58:14.114732 23602 master.cpp:3355] Deactivating agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 at slave(830)@172.17.0.2:60093 (3a9b6161ff79)
3: I1012 16:58:14.114845 23598 hierarchical.cpp:690] Agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0 deactivated
3: I1012 16:58:14.123132 17461 master.cpp:1145] Master terminating
3: I1012 16:58:14.124277 23603 hierarchical.cpp:626] Removed agent 2810b337-fd26-4da8-8ae7-bd5bf059a6b8-S0
3: [       OK ] DiskResource/PersistentVolumeTest.BadACLDropCreateAndDestroy/1 (107 ms)
3: [----------] 34 tests from DiskResource/PersistentVolumeTest (10907 ms total)
3: 
3: [----------] Global test environment tear-down
3: [==========] 1656 tests from 180 test cases ran. (461198 ms total)
3: [  PASSED  ] 1654 tests.
3: [  FAILED  ] 2 tests, listed below:
3: [  FAILED  ] ExecutorAuthorizationTest.RunTaskGroup
3: [  FAILED  ] SlaveTest.RestartSlaveRequireExecutorAuthentication
3: 
3:  2 FAILED TESTS
3:   YOU HAVE 21 DISABLED TESTS
3: 
3: I1012 16:58:14.190513 23605 process.cpp:1068] Failed to accept socket: future discarded
3/3 Test #3: MesosTests .......................***Failed  465.86 sec

67% tests passed, 1 tests failed out of 3

Total Test time (real) = 503.91 sec

The following tests FAILED:
	  3 - MesosTests (Failed)
Errors while running CTest
make[3]: Leaving directory `/mesos/build'
make[3]: *** [CMakeFiles/check] Error 8
make[2]: *** [CMakeFiles/check.dir/all] Error 2
make[2]: Leaving directory `/mesos/build'
make[1]: *** [CMakeFiles/check.dir/rule] Error 2
make[1]: Leaving directory `/mesos/build'
make: *** [check] Error 2
+ docker rmi mesos-1507825106-16220
Untagged: mesos-1507825106-16220:latest
Deleted: sha256:3560c3a6007ba5b75b5a066497298337fbd2bf6bd95d2362c98d9914539b79a7
Deleted: sha256:4361b00d41214669336ae1a78d1d3f848ad0802900b9baa7db5bbaf02a9dc792
Deleted: sha256:d9b796ccde4394c4b2d981e5b0d7c41270be36ce94a561bc9b0ee8cd9c96d238
Deleted: sha256:a11d3131742fe23f11d128146f4cd54a4fbd0e977001223c8f1cc6b22e21159a
Deleted: sha256:55db67d1927e20b8c36140d4e881c2b8bf0826169454f5423b527c0cc8646f94
Deleted: sha256:d37c418ef7c28fddc0296c2622318d9f41529c305ee2851efbaefb2734370517
Deleted: sha256:b710c8a7283299c6f7ef129917f6c8750a3ae33d20f35d2e8d75a41760ec21a3
Deleted: sha256:4f9360de68c90900b11468bdd5485fe483054c3d1edf2e5b459175f39e4c8376
Deleted: sha256:c27013cdab274339ebc224a82f213c581777fff84261d28ef309314fafac4d8d
Deleted: sha256:28afd5775b835c77ce5d70aa223e54309238d74d1dafe26d32ffb7aac13eb0e4
Deleted: sha256:734d2295dd7cf24139b3c073cf6c8165e44980bda0c1ecbc8d73da6894cc8419
Deleted: sha256:5d2bc9136d196a0e5c38e65e1a35c1f67736d4e73e5399bd22a12f64e43ca814
Deleted: sha256:f3bd0932e9515774539c02aeb85c9abd9588635313da581181d919bea565588f
Deleted: sha256:a3194497506eb97eaaa3f13d448fdbfb6cd7c4a6c1eddafbe30b939973bc715b
Deleted: sha256:d8a1b5f3a54390de9c547a3e01ed9b74bb24411237d55cf7a6a24cfcb9fc28d0
Deleted: sha256:3e9394f308e2da1903ff9b65bc88ab20793ce5f467ee86c7cf5c9a6c7730fafd
Deleted: sha256:aa1fc55a955018ad7350063fc3164f6741fdb0eeb92f941b419fa91c9cfa56dc
Deleted: sha256:f7c38a42bfff23837a23fac9655e54c79c64db8bb029c14b0a5e0f20b5df7834
Deleted: sha256:d5bc8cc5ae3eda6d58eb22bb528f0725063abe9019f465d7f3d49c47c10d4dcd
Deleted: sha256:648d94352a73f926a09279277e93914ebe2de88260054b70dcbc2831773cccfa
Deleted: sha256:4ecb9e412b6ce8a398d00c695ea037cf21984f4befa0e28e92eeab950b35fa5d
Deleted: sha256:271be0b44fdf667c1de011c6fd99b660d43952e6dec190f28c83a649c53371cd
Deleted: sha256:0ba1f78a5af4d82a95ec2df1e03dfd05c8389cd2df49348db9e486622ee70f6d
Deleted: sha256:9099f2c805f44934e6c875e936ef659282278a1c888bb73dd54856ea96655eca
Deleted: sha256:4d2cab5af0b58572766365f713ed00f4485bed734f3dc9f84847f4529ab80cf4
Deleted: sha256:c8088b9ffb6a8a4fe6bd2b00fa31cd05da147ac502e0a6c970774c80eae755e4
Deleted: sha256:bbf587eac885e6694a9fb0af39526c3c5f9e2201dc912977e8ef844318a742cf
Deleted: sha256:988375219b874afd08de52b36518f71482af00afb38b7f6061729107f127b505
Build step 'Execute shell' marked build as failure