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/24 04:16:32 UTC

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

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

Changes:

[bmahler] Fixed the flaky MasterTest.IgnoreOldAgentReregistration.

------------------------------------------
[...truncated 29.94 MB...]
3:     type: ANY
3:   }
3:   creator_principals {
3:     type: NONE
3:   }
3: }
3: " --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="false" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/2UdZK0/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_unreachable_tasks_per_framework="1000" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --roles="default-role" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/2UdZK0/master" --zk_session_timeout="10secs"
3: I1024 04:15:05.211155 17199 master.cpp:498] Master allowing unauthenticated frameworks to register
3: I1024 04:15:05.211163 17199 master.cpp:502] Master only allowing authenticated agents to register
3: I1024 04:15:05.211165 17199 master.cpp:508] Master only allowing authenticated HTTP frameworks to register
3: I1024 04:15:05.211170 17199 credentials.hpp:37] Loading credentials for authentication from '/tmp/2UdZK0/credentials'
3: I1024 04:15:05.211450 17199 master.cpp:552] Using default 'crammd5' authenticator
3: I1024 04:15:05.211606 17199 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1024 04:15:05.211766 17199 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1024 04:15:05.211912 17199 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1024 04:15:05.212061 17199 master.cpp:631] Authorization enabled
3: W1024 04:15:05.212079 17199 master.cpp:694] The '--roles' flag is deprecated. This flag will be removed in the future. See the Mesos 0.27 upgrade notes for more information
3: I1024 04:15:05.212311 17192 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1024 04:15:05.212327 17191 whitelist_watcher.cpp:77] No whitelist given
3: I1024 04:15:05.215448 17189 master.cpp:2198] Elected as the leading master!
3: I1024 04:15:05.215487 17189 master.cpp:1687] Recovering from registrar
3: I1024 04:15:05.215698 17195 registrar.cpp:347] Recovering registrar
3: I1024 04:15:05.216517 17195 registrar.cpp:391] Successfully fetched the registry (0B) in 0ns
3: I1024 04:15:05.216648 17195 registrar.cpp:495] Applied 1 operations in 35224ns; attempting to update the registry
3: I1024 04:15:05.217362 17195 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1024 04:15:05.217504 17195 registrar.cpp:424] Successfully recovered registrar
3: I1024 04:15:05.217978 17192 master.cpp:1791] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1024 04:15:05.218024 17186 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: W1024 04:15:05.223480 17185 process.cpp:3193] Attempted to spawn already running process files@172.17.0.2:51271
3: I1024 04:15:05.224439 17185 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1024 04:15:05.224920 17185 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1024 04:15:05.225054 17185 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1024 04:15:05.225087 17185 provisioner.cpp:255] Using default backend 'copy'
3: I1024 04:15:05.226925 17185 cluster.cpp:448] Creating default 'local' authorizer
3: I1024 04:15:05.229080 17190 slave.cpp:254] Mesos agent started on (825)@172.17.0.2:51271
3: W1024 04:15:05.229600 17185 process.cpp:3193] Attempted to spawn already running process version@172.17.0.2:51271
3: I1024 04:15:05.229101 17190 slave.cpp:255] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_BK7dCt/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_BK7dCt/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_BK7dCt/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_BK7dCt/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_BK7dCt/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_92720u\/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_92720u\/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_BK7dCt" --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_eFUCjZ" --zk_session_timeout="10secs"
3: I1024 04:15:05.229693 17190 credentials.hpp:86] Loading credential for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_BK7dCt/credential'
3: I1024 04:15:05.229955 17190 slave.cpp:287] Agent using credential for: test-principal
3: I1024 04:15:05.229976 17190 credentials.hpp:37] Loading credentials for authentication from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_BK7dCt/http_credentials'
3: I1024 04:15:05.230218 17190 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1024 04:15:05.230407 17190 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1024 04:15:05.230584 17185 sched.cpp:232] Version: 1.5.0
3: I1024 04:15:05.231307 17189 sched.cpp:336] New master detected at master@172.17.0.2:51271
3: I1024 04:15:05.231456 17189 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1024 04:15:05.231474 17189 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.2:51271
3: I1024 04:15:05.231606 17189 sched.cpp:853] Will retry registration in 457.497267ms if necessary
3: I1024 04:15:05.231842 17198 master.cpp:2929] Received SUBSCRIBE call for framework 'default' at scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
3: I1024 04:15:05.231947 17198 master.cpp:2263] Authorizing framework principal 'test-principal' to receive offers for roles '{ default-role }'
3: I1024 04:15:05.232547 17196 master.cpp:3009] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1024 04:15:05.233232 17186 sched.cpp:747] Framework registered with e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
3: I1024 04:15:05.233283 17186 sched.cpp:761] Scheduler::registered took 26694ns
3: I1024 04:15:05.233458 17200 hierarchical.cpp:303] Added framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
3: I1024 04:15:05.233639 17200 hierarchical.cpp:1488] Performed allocation for 0 agents in 67593ns
3: I1024 04:15:05.233996 17190 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_92720u\/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_92720u\/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: I1024 04:15:05.234390 17190 slave.cpp:593] Agent attributes: [  ]
3: I1024 04:15:05.234401 17190 slave.cpp:602] Agent hostname: d7bd9f6bb02f
3: I1024 04:15:05.234627 17195 status_update_manager.cpp:177] Pausing sending status updates
3: I1024 04:15:05.236348 17199 state.cpp:64] Recovering state from '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_eFUCjZ/meta'
3: I1024 04:15:05.236651 17199 status_update_manager.cpp:203] Recovering status update manager
3: I1024 04:15:05.236846 17198 containerizer.cpp:662] Recovering containerizer
3: I1024 04:15:05.238634 17189 provisioner.cpp:416] Provisioner recovery complete
3: I1024 04:15:05.239037 17201 slave.cpp:6310] Finished recovery
3: I1024 04:15:05.240103 17196 slave.cpp:993] New master detected at master@172.17.0.2:51271
3: I1024 04:15:05.240155 17191 status_update_manager.cpp:177] Pausing sending status updates
3: I1024 04:15:05.240160 17196 slave.cpp:1028] Detecting new master
3: I1024 04:15:05.241948 17187 slave.cpp:1055] Authenticating with master master@172.17.0.2:51271
3: I1024 04:15:05.242053 17187 slave.cpp:1064] Using default CRAM-MD5 authenticatee
3: I1024 04:15:05.242370 17192 authenticatee.cpp:121] Creating new client SASL connection
3: I1024 04:15:05.242465 17190 hierarchical.cpp:1488] Performed allocation for 0 agents in 102379ns
3: I1024 04:15:05.242772 17192 master.cpp:7947] Authenticating slave(825)@172.17.0.2:51271
3: I1024 04:15:05.242902 17197 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1493)@172.17.0.2:51271
3: I1024 04:15:05.243234 17189 authenticator.cpp:98] Creating new server SASL connection
3: I1024 04:15:05.243451 17199 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1024 04:15:05.243479 17199 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1024 04:15:05.243654 17201 authenticator.cpp:204] Received SASL authentication start
3: I1024 04:15:05.243731 17201 authenticator.cpp:326] Authentication requires more steps
3: I1024 04:15:05.243866 17201 authenticatee.cpp:259] Received SASL authentication step
3: I1024 04:15:05.244036 17201 authenticator.cpp:232] Received SASL authentication step
3: I1024 04:15:05.244076 17201 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd7bd9f6bb02f' server FQDN: 'd7bd9f6bb02f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1024 04:15:05.244092 17201 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1024 04:15:05.244132 17201 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1024 04:15:05.244150 17201 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd7bd9f6bb02f' server FQDN: 'd7bd9f6bb02f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1024 04:15:05.244160 17201 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1024 04:15:05.244166 17201 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1024 04:15:05.244182 17201 authenticator.cpp:318] Authentication success
3: I1024 04:15:05.244300 17191 authenticatee.cpp:299] Authentication success
3: I1024 04:15:05.244413 17195 master.cpp:7977] Successfully authenticated principal 'test-principal' at slave(825)@172.17.0.2:51271
3: I1024 04:15:05.244477 17198 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1493)@172.17.0.2:51271
3: I1024 04:15:05.244652 17191 slave.cpp:1147] Successfully authenticated with master master@172.17.0.2:51271
3: I1024 04:15:05.244976 17191 slave.cpp:1626] Will retry registration in 109666ns if necessary
3: I1024 04:15:05.245292 17190 master.cpp:5801] Received register agent message from slave(825)@172.17.0.2:51271 (d7bd9f6bb02f)
3: I1024 04:15:05.245462 17190 master.cpp:3838] Authorizing agent with principal 'test-principal'
3: I1024 04:15:05.245930 17197 master.cpp:5861] Authorized registration of agent at slave(825)@172.17.0.2:51271 (d7bd9f6bb02f)
3: I1024 04:15:05.246103 17197 master.cpp:5954] Registering agent at slave(825)@172.17.0.2:51271 (d7bd9f6bb02f) with id e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0
3: I1024 04:15:05.246629 17189 registrar.cpp:495] Applied 1 operations in 78427ns; attempting to update the registry
3: I1024 04:15:05.247280 17189 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1024 04:15:05.247550 17201 master.cpp:6001] Admitted agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271 (d7bd9f6bb02f)
3: I1024 04:15:05.248723 17198 slave.cpp:1193] Registered with master master@172.17.0.2:51271; given agent ID e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0
3: I1024 04:15:05.248870 17194 status_update_manager.cpp:184] Resuming sending status updates
3: I1024 04:15:05.249061 17198 slave.cpp:1213] Checkpointing SlaveInfo to '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_eFUCjZ/meta/slaves/e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0/slave.info'
3: I1024 04:15:05.248584 17201 master.cpp:6032] Registered agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271 (d7bd9f6bb02f) 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_92720u\/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_92720u\/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: I1024 04:15:05.249368 17187 hierarchical.cpp:593] Added agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 (d7bd9f6bb02f) with cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048; ports:[31000-32000] (allocated: {})
3: I1024 04:15:05.249547 17198 slave.cpp:1262] Forwarding total oversubscribed resources {}
3: I1024 04:15:05.249737 17198 master.cpp:6828] Received update of agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271 (d7bd9f6bb02f) with total oversubscribed resources {}
3: I1024 04:15:05.249996 17198 master.cpp:6839] Ignoring update on agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271 (d7bd9f6bb02f) as it reports no changes
3: I1024 04:15:05.251550 17187 hierarchical.cpp:1488] Performed allocation for 1 agents in 1.938335ms
3: I1024 04:15:05.252805 17190 master.cpp:7777] Sending 1 offers to framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
3: I1024 04:15:05.253551 17190 sched.cpp:917] Scheduler::resourceOffers took 137592ns
3: I1024 04:15:05.255858 17186 master.cpp:9400] Removing offer e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O0
3: I1024 04:15:05.256062 17186 master.cpp:4196] Processing ACCEPT call for offers: [ e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O0 ] on agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271 (d7bd9f6bb02f) for framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
3: I1024 04:15:05.256304 17186 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_92720u\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: W1024 04:15:05.258607 17186 master.cpp:2348] Dropping CREATE offer operation from framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271: Not authorized to create persistent volumes as 'test-principal'
3: I1024 04:15:05.260695 17195 hierarchical.cpp:1163] Recovered cpus(allocated: default-role):2; mem(allocated: default-role):2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048; ports:[31000-32000], allocated: {}) on agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 from framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
3: I1024 04:15:05.265357 17194 hierarchical.cpp:1488] Performed allocation for 1 agents in 2.661082ms
3: I1024 04:15:05.266644 17201 master.cpp:7777] Sending 1 offers to framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
3: I1024 04:15:05.267550 17191 sched.cpp:917] Scheduler::resourceOffers took 171529ns
3: W1024 04:15:05.268441 17185 process.cpp:3193] Attempted to spawn already running process version@172.17.0.2:51271
3: I1024 04:15:05.268520 17187 master.cpp:5207] Processing DECLINE call for offers: [ e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O1 ] for framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
3: I1024 04:15:05.269392 17185 sched.cpp:232] Version: 1.5.0
3: I1024 04:15:05.269551 17187 master.cpp:9400] Removing offer e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O1
3: I1024 04:15:05.269708 17187 master.cpp:3439] Processing SUPPRESS call for framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
3: I1024 04:15:05.270068 17200 sched.cpp:336] New master detected at master@172.17.0.2:51271
3: I1024 04:15:05.270165 17200 sched.cpp:351] No credentials provided. Attempting to register without authentication
3: I1024 04:15:05.270181 17200 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.2:51271
3: I1024 04:15:05.270293 17200 sched.cpp:853] Will retry registration in 21.250669ms if necessary
3: I1024 04:15:05.270469 17193 master.cpp:2929] Received SUBSCRIBE call for framework 'creator-framework' at scheduler-8ba87918-462b-475c-9659-8dd0821d8ee0@172.17.0.2:51271
3: I1024 04:15:05.270546 17193 master.cpp:2263] Authorizing framework principal 'creator-principal' to receive offers for roles '{ default-role }'
3: I1024 04:15:05.270593 17186 hierarchical.cpp:1163] Recovered cpus(allocated: default-role):2; mem(allocated: default-role):2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048; ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048; ports:[31000-32000], allocated: {}) on agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 from framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
3: I1024 04:15:05.270822 17186 hierarchical.cpp:1275] Suppressed offers for roles { default-role } of framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
3: I1024 04:15:05.271019 17195 master.cpp:3009] Subscribing framework creator-framework with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1024 04:15:05.271539 17188 hierarchical.cpp:303] Added framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
3: I1024 04:15:05.271649 17195 sched.cpp:747] Framework registered with e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
3: I1024 04:15:05.271688 17195 sched.cpp:761] Scheduler::registered took 20399ns
3: I1024 04:15:05.273592 17188 hierarchical.cpp:1488] Performed allocation for 1 agents in 1.887778ms
3: I1024 04:15:05.274567 17188 master.cpp:7777] Sending 1 offers to framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001 (creator-framework) at scheduler-8ba87918-462b-475c-9659-8dd0821d8ee0@172.17.0.2:51271
3: I1024 04:15:05.275259 17188 sched.cpp:917] Scheduler::resourceOffers took 122812ns
3: I1024 04:15:05.277081 17192 hierarchical.cpp:1488] Performed allocation for 1 agents in 136079ns
3: I1024 04:15:05.279171 17200 master.cpp:9400] Removing offer e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O2
3: I1024 04:15:05.279304 17200 master.cpp:4196] Processing ACCEPT call for offers: [ e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O2 ] on agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271 (d7bd9f6bb02f) for framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001 (creator-framework) at scheduler-8ba87918-462b-475c-9659-8dd0821d8ee0@172.17.0.2:51271
3: I1024 04:15:05.279464 17200 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_92720u\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: I1024 04:15:05.281497 17197 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_92720u\/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 e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001 (creator-framework) at scheduler-8ba87918-462b-475c-9659-8dd0821d8ee0@172.17.0.2:51271 to agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271 (d7bd9f6bb02f)
3: I1024 04:15:05.282266 17197 master.cpp:9346] Sending updated checkpointed resources disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048 to agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271 (d7bd9f6bb02f)
3: I1024 04:15:05.284569 17197 slave.cpp:3519] Updated checkpointed resources from {} to disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048
3: I1024 04:15:05.288470 17201 hierarchical.cpp:887] Updated allocation of framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001 on agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-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_92720u/disk1]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/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_92720u/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048
3: I1024 04:15:05.290423 17201 hierarchical.cpp:1163] Recovered cpus(allocated: default-role):2; mem(allocated: default-role):2048; ports(allocated: default-role):[31000-32000]; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048, allocated: {}) on agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 from framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
3: I1024 04:15:05.294348 17188 hierarchical.cpp:1488] Performed allocation for 1 agents in 2.012616ms
3: I1024 04:15:05.295619 17198 master.cpp:7777] Sending 1 offers to framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001 (creator-framework) at scheduler-8ba87918-462b-475c-9659-8dd0821d8ee0@172.17.0.2:51271
3: I1024 04:15:05.296345 17190 sched.cpp:917] Scheduler::resourceOffers took 128797ns
3: I1024 04:15:05.297183 17192 master.cpp:5207] Processing DECLINE call for offers: [ e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O3 ] for framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001 (creator-framework) at scheduler-8ba87918-462b-475c-9659-8dd0821d8ee0@172.17.0.2:51271
3: I1024 04:15:05.298666 17192 master.cpp:9400] Removing offer e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O3
3: I1024 04:15:05.298907 17192 master.cpp:3439] Processing SUPPRESS call for framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001 (creator-framework) at scheduler-8ba87918-462b-475c-9659-8dd0821d8ee0@172.17.0.2:51271
3: I1024 04:15:05.300245 17193 hierarchical.cpp:1163] Recovered cpus(allocated: default-role):2; mem(allocated: default-role):2048; ports(allocated: default-role):[31000-32000]; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048, allocated: {}) on agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 from framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
3: I1024 04:15:05.300541 17193 hierarchical.cpp:1275] Suppressed offers for roles { default-role } of framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
3: I1024 04:15:05.304316 17196 master.cpp:5312] Processing REVIVE call for framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
3: I1024 04:15:05.304538 17200 hierarchical.cpp:1310] Revived offers for roles { default-role } of framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
3: I1024 04:15:05.306929 17200 hierarchical.cpp:1488] Performed allocation for 1 agents in 2.226456ms
3: I1024 04:15:05.308104 17200 master.cpp:7777] Sending 1 offers to framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
3: I1024 04:15:05.308936 17200 sched.cpp:917] Scheduler::resourceOffers took 147808ns
3: I1024 04:15:05.311914 17197 master.cpp:9400] Removing offer e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O4
3: I1024 04:15:05.312069 17197 master.cpp:4196] Processing ACCEPT call for offers: [ e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O4 ] on agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271 (d7bd9f6bb02f) for framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
3: I1024 04:15:05.312268 17197 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_92720u\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: W1024 04:15:05.314090 17191 master.cpp:2348] Dropping DESTROY offer operation from framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271: Not authorized to destroy persistent volumes as 'test-principal'
3: I1024 04:15:05.316246 17193 hierarchical.cpp:1163] Recovered cpus(allocated: default-role):2; mem(allocated: default-role):2048; ports(allocated: default-role):[31000-32000]; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048, allocated: {}) on agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 from framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
3: I1024 04:15:05.323235 17194 hierarchical.cpp:1488] Performed allocation for 1 agents in 1.908591ms
3: I1024 04:15:05.324015 17189 master.cpp:7777] Sending 1 offers to framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
3: I1024 04:15:05.324678 17189 sched.cpp:917] Scheduler::resourceOffers took 106726ns
3: I1024 04:15:05.325139 17185 sched.cpp:2005] Asked to stop the driver
3: I1024 04:15:05.325327 17199 sched.cpp:1187] Stopping framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
3: I1024 04:15:05.325659 17195 master.cpp:8458] Processing TEARDOWN call for framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
3: I1024 04:15:05.325685 17195 master.cpp:8470] Removing framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
3: I1024 04:15:05.325695 17195 master.cpp:3299] Deactivating framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
3: I1024 04:15:05.325773 17185 sched.cpp:2005] Asked to stop the driver
3: I1024 04:15:05.325896 17188 hierarchical.cpp:412] Deactivated framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
3: I1024 04:15:05.325911 17198 sched.cpp:1187] Stopping framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
3: I1024 04:15:05.327076 17195 master.cpp:9400] Removing offer e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O5
3: I1024 04:15:05.327342 17201 slave.cpp:3211] Asked to shut down framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 by master@172.17.0.2:51271
3: I1024 04:15:05.327378 17201 slave.cpp:3226] Cannot shut down unknown framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
3: I1024 04:15:05.327731 17195 master.cpp:8458] Processing TEARDOWN call for framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001 (creator-framework) at scheduler-8ba87918-462b-475c-9659-8dd0821d8ee0@172.17.0.2:51271
3: I1024 04:15:05.327761 17195 master.cpp:8470] Removing framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001 (creator-framework) at scheduler-8ba87918-462b-475c-9659-8dd0821d8ee0@172.17.0.2:51271
3: I1024 04:15:05.327780 17195 master.cpp:3299] Deactivating framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001 (creator-framework) at scheduler-8ba87918-462b-475c-9659-8dd0821d8ee0@172.17.0.2:51271
3: I1024 04:15:05.328126 17191 slave.cpp:3211] Asked to shut down framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001 by master@172.17.0.2:51271
3: I1024 04:15:05.328163 17191 slave.cpp:3226] Cannot shut down unknown framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
3: I1024 04:15:05.328121 17192 hierarchical.cpp:1163] Recovered cpus(allocated: default-role):2; mem(allocated: default-role):2048; ports(allocated: default-role):[31000-32000]; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048; disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048; disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048, allocated: {}) on agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 from framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
3: I1024 04:15:05.328346 17192 hierarchical.cpp:355] Removed framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
3: I1024 04:15:05.328418 17192 hierarchical.cpp:412] Deactivated framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
3: I1024 04:15:05.328644 17192 hierarchical.cpp:355] Removed framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
3: I1024 04:15:05.328961 17185 slave.cpp:869] Agent terminating
3: I1024 04:15:05.329149 17186 master.cpp:1303] Agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271 (d7bd9f6bb02f) disconnected
3: I1024 04:15:05.329174 17186 master.cpp:3336] Disconnecting agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271 (d7bd9f6bb02f)
3: I1024 04:15:05.329253 17186 master.cpp:3355] Deactivating agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271 (d7bd9f6bb02f)
3: I1024 04:15:05.329386 17199 hierarchical.cpp:690] Agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 deactivated
3: I1024 04:15:05.335131 17185 master.cpp:1145] Master terminating
3: I1024 04:15:05.336043 17196 hierarchical.cpp:626] Removed agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0
3: [       OK ] DiskResource/PersistentVolumeTest.BadACLDropCreateAndDestroy/1 (136 ms)
3: [----------] 34 tests from DiskResource/PersistentVolumeTest (15927 ms total)
3: 
3: [----------] Global test environment tear-down
3: [==========] 1649 tests from 178 test cases ran. (415926 ms total)
3: [  PASSED  ] 1648 tests.
3: [  FAILED  ] 1 test, listed below:
3: [  FAILED  ] RegistrarTest.UpdateQuota
3: 
3:  1 FAILED TEST
3:   YOU HAVE 21 DISABLED TESTS
3: 
3: I1024 04:15:05.408042 17202 process.cpp:1067] Failed to accept socket: future discarded
3/3 Test #3: MesosTests .......................***Failed  420.98 sec

67% tests passed, 1 tests failed out of 3

Total Test time (real) = 438.30 sec

The following tests FAILED:
	  3 - MesosTests (Failed)
make[3]: Leaving directory `/mesos/build'
make[2]: Leaving directory `/mesos/build'
make[1]: Leaving directory `/mesos/build'
+ docker rmi mesos-1508815888-26887
Untagged: mesos-1508815888-26887:latest
Deleted: sha256:4d62ea553e773d4f39ff3a898b01bd9cae2886cef92f1452cdf2d4ae7f3dec61
Deleted: sha256:3b0fc3cc5564a99a8fb9d77c83cfeb58217f7e7c5b91692ceb36db6a5064f126
Deleted: sha256:5fc10490f239c5ebf2efb239a5808153aa919d32ef81980e3ca336c971ae7ab1
Deleted: sha256:c498574654714f603a59012712fa6597062bb8ee10bc09ca5c7292c0fe561144
Deleted: sha256:d5229c44dd43d7ee90cfbac08fc1c56d9cdd66a855f1d99b94fba8ce299db261
Deleted: sha256:b76ffb7d7cd9f2af4fd703b32db78501e401e61832aa50a673169b8835f2ffe5
Deleted: sha256:d4fe1ef960025098e428e29b1b27b700bec19f59b5a85620b906f0a54f24da09
Deleted: sha256:65f8f75b91333283e322648a87be168ca0c97de9e41894f5ddf07999e2c8b82d
Deleted: sha256:8c8c04e7f0e51a67a2e7ffb14023cccb21cad9806e6e51358d6e7cf80c8202ef
Deleted: sha256:045c8ca3bcf6e06cbc1ad882723bc6e5dc83bc908017bbd088204e2fd71d8be3
Deleted: sha256:158c679d77e50bbc45deb6adc0de6c49be56c0b9d123c49adc88d7517afe21cc
Deleted: sha256:0500f068e6eda8a463a56bce531924c8d07752355a7a2cd735514a45f478a203
Deleted: sha256:726d2dfe461874ea64245c5c9143274c3533c7ee902ed9ab8eb6c1ac896594e9
Deleted: sha256:e0d7992dcbf4f3c38122fc771b00fa1adee6b897b6d40b99e97b1dd689e9bb34
Deleted: sha256:c9104c2aa37aa20b38c19a7983fd1d384232b60fced9255d526cbd6579c716dd
Deleted: sha256:e0d0738c6d13d79edccc3e5c324e10f3ab35da66d3d8f66a02a816c6a1e4bcfe
Deleted: sha256:ced4af9c481a3d500a3aa51afa6efb709afc6b412002cbaf2bbd20b5036a0aad
Deleted: sha256:4c7f09ddbaeb96e7f1e0a157fb456430d927ab4b7c64405c6770d3b7d3182cf6
Deleted: sha256:de4882cacdce27c67fc7caf0137c1bd1a02beed39f497f45c84924133dc9f2a3
Deleted: sha256:423513bf19a297f5c34b86126e05a7d5d6ee1db6a3a2c1ed17af6003b1f02b1a
Deleted: sha256:c2a1bc31516401deec262e14aeb2d3d1e1ed790c818b3d7c9792e9c75ccdd405
Deleted: sha256:ce12f227c8b07fce2620b446f1b394667983a484a3a75aabe438f578cbf0ec13
Deleted: sha256:3882504ff4592a23ec241b8bf28dff41ab2b2cfffab7ac4f5f18eab580d1b1e2
Deleted: sha256:30b45c476d6a95a5ccce556a64c2a5676dc122654020bea141e91c3022ac9cc8
Deleted: sha256:a69321fba53e9ac063b6f19bd6da89717daa60f466d8bdf1191fa81d52049706
Deleted: sha256:38b487206307d129dbe747cbc848eca09ecaef6dc83526273e21f26115bdfbf6
Deleted: sha256:e7d0b9c4fa24a24efcaededd1dfac33d98889874816260241bda944ed7a7ef5c
Deleted: sha256:19abba379dfa35cf4961480672ba2bf0c8a0518bc656774cdba4b9774a4a9e0b
Build step 'Execute shell' marked build as failure

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

Posted by Apache Jenkins Server <je...@builds.apache.org>.

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

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

Posted by Benjamin Mahler <bm...@apache.org>.

This looks like a timeout:

3: I1024 04:12:32.741120 17193 replica.cpp:540] Replica received write
request for position 1 from __req_res__(1523)@172.17.0.2:51271
3: I1024 04:12:32.741189 17201 replica.cpp:540] Replica received write
request for position 1 from __req_res__(1524)@172.17.0.2:51271
3: I1024 04:12:32.741619 17201 leveldb.cpp:341] Persisting action (193
bytes) to leveldb took 388173ns
3: I1024 04:12:32.741619 17193 leveldb.cpp:341] Persisting action (193
bytes) to leveldb took 461690ns
3: *I1024 04:12:43.419662* 17193 replica.cpp:711] Persisted action APPEND
at position 1
3: *E1024 04:12:42.741019* 17195 registrar.cpp:575] Registrar aborting:
Failed to update registry: Failed to perform store within 10secs
3: *I1024 04:12:32.741649* 17201 replica.cpp:711] Persisted action APPEND
at position 1
3: /mesos/src/tests/registrar_tests.cpp:897: Failure
3: (registry).failure(): Failed to recover registrar: Failed to persist
MasterInfo: Failed to update registry: Failed to perform store within 10secs
3: [  FAILED  ] RegistrarTest.UpdateQuota (10720 ms)

Seems like thread 17201 was starved after getting its log timestamp but
before writing to the log. Probably 10 seconds is too low for apache CI.

I'll bump the existing timeout to match the default of 15 seconds used for
AWAIT_.

On Mon, Oct 23, 2017 at 9:16 PM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:

> See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=
> cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers,
> ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,
> label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)
> &&(!H23)/4359/display/redirect?page=changes>
>
> Changes:
>
> [bmahler] Fixed the flaky MasterTest.IgnoreOldAgentReregistration.
>
> ------------------------------------------
> [...truncated 29.94 MB...]
> 3:     type: ANY
> 3:   }
> 3:   creator_principals {
> 3:     type: NONE
> 3:   }
> 3: }
> 3: " --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate_agents="true" --authenticate_frameworks="false"
> --authenticate_http_frameworks="true" --authenticate_http_readonly="true"
> --authenticate_http_readwrite="true" --authenticators="crammd5"
> --authorizers="local" --credentials="/tmp/2UdZK0/credentials"
> --filter_gpu_resources="true" --framework_sorter="drf" --help="false"
> --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic"
> --initialize_driver_logging="true" --log_auto_initialize="true"
> --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5"
> --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
> --max_unreachable_tasks_per_framework="1000" --port="5050"
> --quiet="false" --recovery_agent_removal_limit="100%"
> --registry="in_memory" --registry_fetch_timeout="1mins"
> --registry_gc_interval="15mins" --registry_max_agent_age="2weeks"
> --registry_max_agent_count="102400" --registry_store_timeout="100secs"
> --registry_strict="false" --roles="default-role" --root_submissions="true"
> --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui"
> --work_dir="/tmp/2UdZK0/master" --zk_session_timeout="10secs"
> 3: I1024 04:15:05.211155 17199 master.cpp:498] Master allowing
> unauthenticated frameworks to register
> 3: I1024 04:15:05.211163 17199 master.cpp:502] Master only allowing
> authenticated agents to register
> 3: I1024 04:15:05.211165 17199 master.cpp:508] Master only allowing
> authenticated HTTP frameworks to register
> 3: I1024 04:15:05.211170 17199 credentials.hpp:37] Loading credentials for
> authentication from '/tmp/2UdZK0/credentials'
> 3: I1024 04:15:05.211450 17199 master.cpp:552] Using default 'crammd5'
> authenticator
> 3: I1024 04:15:05.211606 17199 http.cpp:1045] Creating default 'basic'
> HTTP authenticator for realm 'mesos-master-readonly'
> 3: I1024 04:15:05.211766 17199 http.cpp:1045] Creating default 'basic'
> HTTP authenticator for realm 'mesos-master-readwrite'
> 3: I1024 04:15:05.211912 17199 http.cpp:1045] Creating default 'basic'
> HTTP authenticator for realm 'mesos-master-scheduler'
> 3: I1024 04:15:05.212061 17199 master.cpp:631] Authorization enabled
> 3: W1024 04:15:05.212079 17199 master.cpp:694] The '--roles' flag is
> deprecated. This flag will be removed in the future. See the Mesos 0.27
> upgrade notes for more information
> 3: I1024 04:15:05.212311 17192 hierarchical.cpp:171] Initialized
> hierarchical allocator process
> 3: I1024 04:15:05.212327 17191 whitelist_watcher.cpp:77] No whitelist given
> 3: I1024 04:15:05.215448 17189 master.cpp:2198] Elected as the leading
> master!
> 3: I1024 04:15:05.215487 17189 master.cpp:1687] Recovering from registrar
> 3: I1024 04:15:05.215698 17195 registrar.cpp:347] Recovering registrar
> 3: I1024 04:15:05.216517 17195 registrar.cpp:391] Successfully fetched the
> registry (0B) in 0ns
> 3: I1024 04:15:05.216648 17195 registrar.cpp:495] Applied 1 operations in
> 35224ns; attempting to update the registry
> 3: I1024 04:15:05.217362 17195 registrar.cpp:552] Successfully updated the
> registry in 0ns
> 3: I1024 04:15:05.217504 17195 registrar.cpp:424] Successfully recovered
> registrar
> 3: I1024 04:15:05.217978 17192 master.cpp:1791] Recovered 0 agents from
> the registry (129B); allowing 10mins for agents to re-register
> 3: I1024 04:15:05.218024 17186 hierarchical.cpp:209] Skipping recovery of
> hierarchical allocator: nothing to recover
> 3: W1024 04:15:05.223480 17185 process.cpp:3193] Attempted to spawn
> already running process files@172.17.0.2:51271
> 3: I1024 04:15:05.224439 17185 containerizer.cpp:301] Using isolation {
> environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
> 3: W1024 04:15:05.224920 17185 backend.cpp:76] Failed to create 'aufs'
> backend: AufsBackend requires root privileges
> 3: W1024 04:15:05.225054 17185 backend.cpp:76] Failed to create 'bind'
> backend: BindBackend requires root privileges
> 3: I1024 04:15:05.225087 17185 provisioner.cpp:255] Using default backend
> 'copy'
> 3: I1024 04:15:05.226925 17185 cluster.cpp:448] Creating default 'local'
> authorizer
> 3: I1024 04:15:05.229080 17190 slave.cpp:254] Mesos agent started on (825)@
> 172.17.0.2:51271
> 3: W1024 04:15:05.229600 17185 process.cpp:3193] Attempted to spawn
> already running process version@172.17.0.2:51271
> 3: I1024 04:15:05.229101 17190 slave.cpp:255] Flags at startup: --acls=""
> --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/
> DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_BK7dCt/store/appc"
> --authenticate_http_readonly="true" --authenticate_http_readwrite="true"
> --authenticatee="crammd5" --authentication_backoff_factor="1secs"
> --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false"
> --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup"
> --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs"
> --containerizers="mesos" --credential="/tmp/DiskResource_
> PersistentVolumeTest_BadACLDropCreateAndDestroy_1_BK7dCt/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_BK7dCt/store/docker"
> --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume"
> --enforce_container_disk_quota="false" --executor_registration_timeout="1mins"
> --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs"
> --fetcher_cache_dir="/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_BK7dCt/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_BK7dCt/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_
> 92720u\/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_92720u\/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_BK7dCt"
> --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_eFUCjZ" --zk_session_timeout="10secs"
> 3: I1024 04:15:05.229693 17190 credentials.hpp:86] Loading credential for
> authentication from '/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_BK7dCt/credential'
> 3: I1024 04:15:05.229955 17190 slave.cpp:287] Agent using credential for:
> test-principal
> 3: I1024 04:15:05.229976 17190 credentials.hpp:37] Loading credentials for
> authentication from '/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_BK7dCt/http_credentials'
> 3: I1024 04:15:05.230218 17190 http.cpp:1045] Creating default 'basic'
> HTTP authenticator for realm 'mesos-agent-readonly'
> 3: I1024 04:15:05.230407 17190 http.cpp:1045] Creating default 'basic'
> HTTP authenticator for realm 'mesos-agent-readwrite'
> 3: I1024 04:15:05.230584 17185 sched.cpp:232] Version: 1.5.0
> 3: I1024 04:15:05.231307 17189 sched.cpp:336] New master detected at
> master@172.17.0.2:51271
> 3: I1024 04:15:05.231456 17189 sched.cpp:351] No credentials provided.
> Attempting to register without authentication
> 3: I1024 04:15:05.231474 17189 sched.cpp:820] Sending SUBSCRIBE call to
> master@172.17.0.2:51271
> 3: I1024 04:15:05.231606 17189 sched.cpp:853] Will retry registration in
> 457.497267ms if necessary
> 3: I1024 04:15:05.231842 17198 master.cpp:2929] Received SUBSCRIBE call
> for framework 'default' at scheduler-6e987ae3-fa6a-411a-
> 85f6-b826fa41793f@172.17.0.2:51271
> 3: I1024 04:15:05.231947 17198 master.cpp:2263] Authorizing framework
> principal 'test-principal' to receive offers for roles '{ default-role }'
> 3: I1024 04:15:05.232547 17196 master.cpp:3009] Subscribing framework
> default with checkpointing disabled and capabilities [
> RESERVATION_REFINEMENT ]
> 3: I1024 04:15:05.233232 17186 sched.cpp:747] Framework registered with
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
> 3: I1024 04:15:05.233283 17186 sched.cpp:761] Scheduler::registered took
> 26694ns
> 3: I1024 04:15:05.233458 17200 hierarchical.cpp:303] Added framework
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
> 3: I1024 04:15:05.233639 17200 hierarchical.cpp:1488] Performed allocation
> for 0 agents in 67593ns
> 3: I1024 04:15:05.233996 17190 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_92720u\/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_
> 92720u\/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: I1024 04:15:05.234390 17190 slave.cpp:593] Agent attributes: [  ]
> 3: I1024 04:15:05.234401 17190 slave.cpp:602] Agent hostname: d7bd9f6bb02f
> 3: I1024 04:15:05.234627 17195 status_update_manager.cpp:177] Pausing
> sending status updates
> 3: I1024 04:15:05.236348 17199 state.cpp:64] Recovering state from
> '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_
> eFUCjZ/meta'
> 3: I1024 04:15:05.236651 17199 status_update_manager.cpp:203] Recovering
> status update manager
> 3: I1024 04:15:05.236846 17198 containerizer.cpp:662] Recovering
> containerizer
> 3: I1024 04:15:05.238634 17189 provisioner.cpp:416] Provisioner recovery
> complete
> 3: I1024 04:15:05.239037 17201 slave.cpp:6310] Finished recovery
> 3: I1024 04:15:05.240103 17196 slave.cpp:993] New master detected at
> master@172.17.0.2:51271
> 3: I1024 04:15:05.240155 17191 status_update_manager.cpp:177] Pausing
> sending status updates
> 3: I1024 04:15:05.240160 17196 slave.cpp:1028] Detecting new master
> 3: I1024 04:15:05.241948 17187 slave.cpp:1055] Authenticating with master
> master@172.17.0.2:51271
> 3: I1024 04:15:05.242053 17187 slave.cpp:1064] Using default CRAM-MD5
> authenticatee
> 3: I1024 04:15:05.242370 17192 authenticatee.cpp:121] Creating new client
> SASL connection
> 3: I1024 04:15:05.242465 17190 hierarchical.cpp:1488] Performed allocation
> for 0 agents in 102379ns
> 3: I1024 04:15:05.242772 17192 master.cpp:7947] Authenticating slave(825)@
> 172.17.0.2:51271
> 3: I1024 04:15:05.242902 17197 authenticator.cpp:414] Starting
> authentication session for crammd5-authenticatee(1493)@172.17.0.2:51271
> 3: I1024 04:15:05.243234 17189 authenticator.cpp:98] Creating new server
> SASL connection
> 3: I1024 04:15:05.243451 17199 authenticatee.cpp:213] Received SASL
> authentication mechanisms: CRAM-MD5
> 3: I1024 04:15:05.243479 17199 authenticatee.cpp:239] Attempting to
> authenticate with mechanism 'CRAM-MD5'
> 3: I1024 04:15:05.243654 17201 authenticator.cpp:204] Received SASL
> authentication start
> 3: I1024 04:15:05.243731 17201 authenticator.cpp:326] Authentication
> requires more steps
> 3: I1024 04:15:05.243866 17201 authenticatee.cpp:259] Received SASL
> authentication step
> 3: I1024 04:15:05.244036 17201 authenticator.cpp:232] Received SASL
> authentication step
> 3: I1024 04:15:05.244076 17201 auxprop.cpp:109] Request to lookup
> properties for user: 'test-principal' realm: 'd7bd9f6bb02f' server FQDN:
> 'd7bd9f6bb02f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> 3: I1024 04:15:05.244092 17201 auxprop.cpp:181] Looking up auxiliary
> property '*userPassword'
> 3: I1024 04:15:05.244132 17201 auxprop.cpp:181] Looking up auxiliary
> property '*cmusaslsecretCRAM-MD5'
> 3: I1024 04:15:05.244150 17201 auxprop.cpp:109] Request to lookup
> properties for user: 'test-principal' realm: 'd7bd9f6bb02f' server FQDN:
> 'd7bd9f6bb02f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> 3: I1024 04:15:05.244160 17201 auxprop.cpp:131] Skipping auxiliary
> property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> 3: I1024 04:15:05.244166 17201 auxprop.cpp:131] Skipping auxiliary
> property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> 3: I1024 04:15:05.244182 17201 authenticator.cpp:318] Authentication
> success
> 3: I1024 04:15:05.244300 17191 authenticatee.cpp:299] Authentication
> success
> 3: I1024 04:15:05.244413 17195 master.cpp:7977] Successfully authenticated
> principal 'test-principal' at slave(825)@172.17.0.2:51271
> 3: I1024 04:15:05.244477 17198 authenticator.cpp:432] Authentication
> session cleanup for crammd5-authenticatee(1493)@172.17.0.2:51271
> 3: I1024 04:15:05.244652 17191 slave.cpp:1147] Successfully authenticated
> with master master@172.17.0.2:51271
> 3: I1024 04:15:05.244976 17191 slave.cpp:1626] Will retry registration in
> 109666ns if necessary
> 3: I1024 04:15:05.245292 17190 master.cpp:5801] Received register agent
> message from slave(825)@172.17.0.2:51271 (d7bd9f6bb02f)
> 3: I1024 04:15:05.245462 17190 master.cpp:3838] Authorizing agent with
> principal 'test-principal'
> 3: I1024 04:15:05.245930 17197 master.cpp:5861] Authorized registration of
> agent at slave(825)@172.17.0.2:51271 (d7bd9f6bb02f)
> 3: I1024 04:15:05.246103 17197 master.cpp:5954] Registering agent at
> slave(825)@172.17.0.2:51271 (d7bd9f6bb02f) with id
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0
> 3: I1024 04:15:05.246629 17189 registrar.cpp:495] Applied 1 operations in
> 78427ns; attempting to update the registry
> 3: I1024 04:15:05.247280 17189 registrar.cpp:552] Successfully updated the
> registry in 0ns
> 3: I1024 04:15:05.247550 17201 master.cpp:6001] Admitted agent
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271
> (d7bd9f6bb02f)
> 3: I1024 04:15:05.248723 17198 slave.cpp:1193] Registered with master
> master@172.17.0.2:51271; given agent ID e2b3b6bf-a81a-4ec6-ac70-
> 0731f2054e7d-S0
> 3: I1024 04:15:05.248870 17194 status_update_manager.cpp:184] Resuming
> sending status updates
> 3: I1024 04:15:05.249061 17198 slave.cpp:1213] Checkpointing SlaveInfo to
> '/tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_
> eFUCjZ/meta/slaves/e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0/slave.info'
> 3: I1024 04:15:05.248584 17201 master.cpp:6032] Registered agent
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271
> (d7bd9f6bb02f) 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_92720u\/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_
> 92720u\/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: I1024 04:15:05.249368 17187 hierarchical.cpp:593] Added agent
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 (d7bd9f6bb02f) with cpus:2;
> mem:2048; disk(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1]:2048;
> disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_
> PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048;
> ports:[31000-32000] (allocated: {})
> 3: I1024 04:15:05.249547 17198 slave.cpp:1262] Forwarding total
> oversubscribed resources {}
> 3: I1024 04:15:05.249737 17198 master.cpp:6828] Received update of agent
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271
> (d7bd9f6bb02f) with total oversubscribed resources {}
> 3: I1024 04:15:05.249996 17198 master.cpp:6839] Ignoring update on agent
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271
> (d7bd9f6bb02f) as it reports no changes
> 3: I1024 04:15:05.251550 17187 hierarchical.cpp:1488] Performed allocation
> for 1 agents in 1.938335ms
> 3: I1024 04:15:05.252805 17190 master.cpp:7777] Sending 1 offers to
> framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at
> scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
> 3: I1024 04:15:05.253551 17190 sched.cpp:917] Scheduler::resourceOffers
> took 137592ns
> 3: I1024 04:15:05.255858 17186 master.cpp:9400] Removing offer
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O0
> 3: I1024 04:15:05.256062 17186 master.cpp:4196] Processing ACCEPT call for
> offers: [ e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O0 ] on agent
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271
> (d7bd9f6bb02f) for framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
> (default) at scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:
> 51271
> 3: I1024 04:15:05.256304 17186 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_
> 92720u\/disk1"},"type":"PATH"},"volume":{"container_path":"
> path1","mode":"RW"}},"name":"disk","reservations":[{"role":
> "default-role","type":"STATIC"}],"scalar":{"value":2048.0},"
> type":"SCALAR"}]'
> 3: W1024 04:15:05.258607 17186 master.cpp:2348] Dropping CREATE offer
> operation from framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
> (default) at scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:
> 51271: Not authorized to create persistent volumes as 'test-principal'
> 3: I1024 04:15:05.260695 17195 hierarchical.cpp:1163] Recovered
> cpus(allocated: default-role):2; mem(allocated: default-role):2048;
> disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1]:2048;
> disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048;
> ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048;
> disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_
> PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1]:2048;
> disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_
> PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048;
> ports:[31000-32000], allocated: {}) on agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0
> from framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
> 3: I1024 04:15:05.265357 17194 hierarchical.cpp:1488] Performed allocation
> for 1 agents in 2.661082ms
> 3: I1024 04:15:05.266644 17201 master.cpp:7777] Sending 1 offers to
> framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at
> scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
> 3: I1024 04:15:05.267550 17191 sched.cpp:917] Scheduler::resourceOffers
> took 171529ns
> 3: W1024 04:15:05.268441 17185 process.cpp:3193] Attempted to spawn
> already running process version@172.17.0.2:51271
> 3: I1024 04:15:05.268520 17187 master.cpp:5207] Processing DECLINE call
> for offers: [ e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O1 ] for framework
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at
> scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
> 3: I1024 04:15:05.269392 17185 sched.cpp:232] Version: 1.5.0
> 3: I1024 04:15:05.269551 17187 master.cpp:9400] Removing offer
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O1
> 3: I1024 04:15:05.269708 17187 master.cpp:3439] Processing SUPPRESS call
> for framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at
> scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
> 3: I1024 04:15:05.270068 17200 sched.cpp:336] New master detected at
> master@172.17.0.2:51271
> 3: I1024 04:15:05.270165 17200 sched.cpp:351] No credentials provided.
> Attempting to register without authentication
> 3: I1024 04:15:05.270181 17200 sched.cpp:820] Sending SUBSCRIBE call to
> master@172.17.0.2:51271
> 3: I1024 04:15:05.270293 17200 sched.cpp:853] Will retry registration in
> 21.250669ms if necessary
> 3: I1024 04:15:05.270469 17193 master.cpp:2929] Received SUBSCRIBE call
> for framework 'creator-framework' at scheduler-8ba87918-462b-475c-
> 9659-8dd0821d8ee0@172.17.0.2:51271
> 3: I1024 04:15:05.270546 17193 master.cpp:2263] Authorizing framework
> principal 'creator-principal' to receive offers for roles '{ default-role }'
> 3: I1024 04:15:05.270593 17186 hierarchical.cpp:1163] Recovered
> cpus(allocated: default-role):2; mem(allocated: default-role):2048;
> disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1]:2048;
> disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048;
> ports(allocated: default-role):[31000-32000] (total: cpus:2; mem:2048;
> disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_
> PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1]:2048;
> disk(reservations: [(STATIC,default-role)])[PATH:/tmp/DiskResource_
> PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048;
> ports:[31000-32000], allocated: {}) on agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0
> from framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
> 3: I1024 04:15:05.270822 17186 hierarchical.cpp:1275] Suppressed offers
> for roles { default-role } of framework e2b3b6bf-a81a-4ec6-ac70-
> 0731f2054e7d-0000
> 3: I1024 04:15:05.271019 17195 master.cpp:3009] Subscribing framework
> creator-framework with checkpointing disabled and capabilities [
> RESERVATION_REFINEMENT ]
> 3: I1024 04:15:05.271539 17188 hierarchical.cpp:303] Added framework
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
> 3: I1024 04:15:05.271649 17195 sched.cpp:747] Framework registered with
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
> 3: I1024 04:15:05.271688 17195 sched.cpp:761] Scheduler::registered took
> 20399ns
> 3: I1024 04:15:05.273592 17188 hierarchical.cpp:1488] Performed allocation
> for 1 agents in 1.887778ms
> 3: I1024 04:15:05.274567 17188 master.cpp:7777] Sending 1 offers to
> framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001 (creator-framework)
> at scheduler-8ba87918-462b-475c-9659-8dd0821d8ee0@172.17.0.2:51271
> 3: I1024 04:15:05.275259 17188 sched.cpp:917] Scheduler::resourceOffers
> took 122812ns
> 3: I1024 04:15:05.277081 17192 hierarchical.cpp:1488] Performed allocation
> for 1 agents in 136079ns
> 3: I1024 04:15:05.279171 17200 master.cpp:9400] Removing offer
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O2
> 3: I1024 04:15:05.279304 17200 master.cpp:4196] Processing ACCEPT call for
> offers: [ e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O2 ] on agent
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271
> (d7bd9f6bb02f) for framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
> (creator-framework) at scheduler-8ba87918-462b-475c-
> 9659-8dd0821d8ee0@172.17.0.2:51271
> 3: I1024 04:15:05.279464 17200 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_
> 92720u\/disk1"},"type":"PATH"},"volume":{"container_path":"
> path1","mode":"RW"}},"name":"disk","reservations":[{"role":
> "default-role","type":"STATIC"}],"scalar":{"value":2048.0},"
> type":"SCALAR"}]'
> 3: I1024 04:15:05.281497 17197 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_92720u\/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
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001 (creator-framework) at
> scheduler-8ba87918-462b-475c-9659-8dd0821d8ee0@172.17.0.2:51271 to agent
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271
> (d7bd9f6bb02f)
> 3: I1024 04:15:05.282266 17197 master.cpp:9346] Sending updated
> checkpointed resources disk(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048
> to agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@
> 172.17.0.2:51271 (d7bd9f6bb02f)
> 3: I1024 04:15:05.284569 17197 slave.cpp:3519] Updated checkpointed
> resources from {} to disk(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_
> 92720u/disk1,id1:path1]:2048
> 3: I1024 04:15:05.288470 17201 hierarchical.cpp:887] Updated allocation of
> framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001 on agent
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-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_92720u/disk1]:2048;
> disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/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_92720u/disk2]:2048; disk(allocated:
> default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_
> 92720u/disk1,id1:path1]:2048
> 3: I1024 04:15:05.290423 17201 hierarchical.cpp:1163] Recovered
> cpus(allocated: default-role):2; mem(allocated: default-role):2048;
> ports(allocated: default-role):[31000-32000]; disk(allocated:
> default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048;
> disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048
> (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations:
> [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_92720u/disk2]:2048; disk(reservations:
> [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048, allocated: {})
> on agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 from framework
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
> 3: I1024 04:15:05.294348 17188 hierarchical.cpp:1488] Performed allocation
> for 1 agents in 2.012616ms
> 3: I1024 04:15:05.295619 17198 master.cpp:7777] Sending 1 offers to
> framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001 (creator-framework)
> at scheduler-8ba87918-462b-475c-9659-8dd0821d8ee0@172.17.0.2:51271
> 3: I1024 04:15:05.296345 17190 sched.cpp:917] Scheduler::resourceOffers
> took 128797ns
> 3: I1024 04:15:05.297183 17192 master.cpp:5207] Processing DECLINE call
> for offers: [ e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O3 ] for framework
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001 (creator-framework) at
> scheduler-8ba87918-462b-475c-9659-8dd0821d8ee0@172.17.0.2:51271
> 3: I1024 04:15:05.298666 17192 master.cpp:9400] Removing offer
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O3
> 3: I1024 04:15:05.298907 17192 master.cpp:3439] Processing SUPPRESS call
> for framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
> (creator-framework) at scheduler-8ba87918-462b-475c-
> 9659-8dd0821d8ee0@172.17.0.2:51271
> 3: I1024 04:15:05.300245 17193 hierarchical.cpp:1163] Recovered
> cpus(allocated: default-role):2; mem(allocated: default-role):2048;
> ports(allocated: default-role):[31000-32000]; disk(allocated:
> default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048;
> disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048
> (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations:
> [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_92720u/disk2]:2048; disk(reservations:
> [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048, allocated: {})
> on agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 from framework
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
> 3: I1024 04:15:05.300541 17193 hierarchical.cpp:1275] Suppressed offers
> for roles { default-role } of framework e2b3b6bf-a81a-4ec6-ac70-
> 0731f2054e7d-0001
> 3: I1024 04:15:05.304316 17196 master.cpp:5312] Processing REVIVE call for
> framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at
> scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
> 3: I1024 04:15:05.304538 17200 hierarchical.cpp:1310] Revived offers for
> roles { default-role } of framework e2b3b6bf-a81a-4ec6-ac70-
> 0731f2054e7d-0000
> 3: I1024 04:15:05.306929 17200 hierarchical.cpp:1488] Performed allocation
> for 1 agents in 2.226456ms
> 3: I1024 04:15:05.308104 17200 master.cpp:7777] Sending 1 offers to
> framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at
> scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
> 3: I1024 04:15:05.308936 17200 sched.cpp:917] Scheduler::resourceOffers
> took 147808ns
> 3: I1024 04:15:05.311914 17197 master.cpp:9400] Removing offer
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O4
> 3: I1024 04:15:05.312069 17197 master.cpp:4196] Processing ACCEPT call for
> offers: [ e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O4 ] on agent
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271
> (d7bd9f6bb02f) for framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
> (default) at scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:
> 51271
> 3: I1024 04:15:05.312268 17197 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_
> 92720u\/disk1"},"type":"PATH"},"volume":{"container_path":"
> path1","mode":"RW"}},"name":"disk","reservations":[{"role":
> "default-role","type":"STATIC"}],"scalar":{"value":2048.0},"
> type":"SCALAR"}]'
> 3: W1024 04:15:05.314090 17191 master.cpp:2348] Dropping DESTROY offer
> operation from framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
> (default) at scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:
> 51271: Not authorized to destroy persistent volumes as 'test-principal'
> 3: I1024 04:15:05.316246 17193 hierarchical.cpp:1163] Recovered
> cpus(allocated: default-role):2; mem(allocated: default-role):2048;
> ports(allocated: default-role):[31000-32000]; disk(allocated:
> default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048;
> disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048
> (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations:
> [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_92720u/disk2]:2048; disk(reservations:
> [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048, allocated: {})
> on agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 from framework
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
> 3: I1024 04:15:05.323235 17194 hierarchical.cpp:1488] Performed allocation
> for 1 agents in 1.908591ms
> 3: I1024 04:15:05.324015 17189 master.cpp:7777] Sending 1 offers to
> framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at
> scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
> 3: I1024 04:15:05.324678 17189 sched.cpp:917] Scheduler::resourceOffers
> took 106726ns
> 3: I1024 04:15:05.325139 17185 sched.cpp:2005] Asked to stop the driver
> 3: I1024 04:15:05.325327 17199 sched.cpp:1187] Stopping framework
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
> 3: I1024 04:15:05.325659 17195 master.cpp:8458] Processing TEARDOWN call
> for framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at
> scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
> 3: I1024 04:15:05.325685 17195 master.cpp:8470] Removing framework
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at
> scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
> 3: I1024 04:15:05.325695 17195 master.cpp:3299] Deactivating framework
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 (default) at
> scheduler-6e987ae3-fa6a-411a-85f6-b826fa41793f@172.17.0.2:51271
> 3: I1024 04:15:05.325773 17185 sched.cpp:2005] Asked to stop the driver
> 3: I1024 04:15:05.325896 17188 hierarchical.cpp:412] Deactivated framework
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
> 3: I1024 04:15:05.325911 17198 sched.cpp:1187] Stopping framework
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
> 3: I1024 04:15:05.327076 17195 master.cpp:9400] Removing offer
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-O5
> 3: I1024 04:15:05.327342 17201 slave.cpp:3211] Asked to shut down
> framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000 by
> master@172.17.0.2:51271
> 3: I1024 04:15:05.327378 17201 slave.cpp:3226] Cannot shut down unknown
> framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
> 3: I1024 04:15:05.327731 17195 master.cpp:8458] Processing TEARDOWN call
> for framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
> (creator-framework) at scheduler-8ba87918-462b-475c-
> 9659-8dd0821d8ee0@172.17.0.2:51271
> 3: I1024 04:15:05.327761 17195 master.cpp:8470] Removing framework
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001 (creator-framework) at
> scheduler-8ba87918-462b-475c-9659-8dd0821d8ee0@172.17.0.2:51271
> 3: I1024 04:15:05.327780 17195 master.cpp:3299] Deactivating framework
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001 (creator-framework) at
> scheduler-8ba87918-462b-475c-9659-8dd0821d8ee0@172.17.0.2:51271
> 3: I1024 04:15:05.328126 17191 slave.cpp:3211] Asked to shut down
> framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001 by
> master@172.17.0.2:51271
> 3: I1024 04:15:05.328163 17191 slave.cpp:3226] Cannot shut down unknown
> framework e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
> 3: I1024 04:15:05.328121 17192 hierarchical.cpp:1163] Recovered
> cpus(allocated: default-role):2; mem(allocated: default-role):2048;
> ports(allocated: default-role):[31000-32000]; disk(allocated:
> default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk2]:2048;
> disk(allocated: default-role)(reservations: [(STATIC,default-role)])[PATH:
> /tmp/DiskResource_PersistentVolumeTest_BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048
> (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations:
> [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_92720u/disk2]:2048; disk(reservations:
> [(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_
> BadACLDropCreateAndDestroy_1_92720u/disk1,id1:path1]:2048, allocated: {})
> on agent e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 from framework
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
> 3: I1024 04:15:05.328346 17192 hierarchical.cpp:355] Removed framework
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0000
> 3: I1024 04:15:05.328418 17192 hierarchical.cpp:412] Deactivated framework
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
> 3: I1024 04:15:05.328644 17192 hierarchical.cpp:355] Removed framework
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-0001
> 3: I1024 04:15:05.328961 17185 slave.cpp:869] Agent terminating
> 3: I1024 04:15:05.329149 17186 master.cpp:1303] Agent
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271
> (d7bd9f6bb02f) disconnected
> 3: I1024 04:15:05.329174 17186 master.cpp:3336] Disconnecting agent
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271
> (d7bd9f6bb02f)
> 3: I1024 04:15:05.329253 17186 master.cpp:3355] Deactivating agent
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 at slave(825)@172.17.0.2:51271
> (d7bd9f6bb02f)
> 3: I1024 04:15:05.329386 17199 hierarchical.cpp:690] Agent
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0 deactivated
> 3: I1024 04:15:05.335131 17185 master.cpp:1145] Master terminating
> 3: I1024 04:15:05.336043 17196 hierarchical.cpp:626] Removed agent
> e2b3b6bf-a81a-4ec6-ac70-0731f2054e7d-S0
> 3: [       OK ] DiskResource/PersistentVolumeTest.BadACLDropCreateAndDestroy/1
> (136 ms)
> 3: [----------] 34 tests from DiskResource/PersistentVolumeTest (15927 ms
> total)
> 3:
> 3: [----------] Global test environment tear-down
> 3: [==========] 1649 tests from 178 test cases ran. (415926 ms total)
> 3: [  PASSED  ] 1648 tests.
> 3: [  FAILED  ] 1 test, listed below:
> 3: [  FAILED  ] RegistrarTest.UpdateQuota
> 3:
> 3:  1 FAILED TEST
> 3:   YOU HAVE 21 DISABLED TESTS
> 3:
> 3: I1024 04:15:05.408042 17202 process.cpp:1067] Failed to accept socket:
> future discarded
> 3/3 Test #3: MesosTests .......................***Failed  420.98 sec
>
> 67% tests passed, 1 tests failed out of 3
>
> Total Test time (real) = 438.30 sec
>
> The following tests FAILED:
>           3 - MesosTests (Failed)
> make[3]: Leaving directory `/mesos/build'
> make[2]: Leaving directory `/mesos/build'
> make[1]: Leaving directory `/mesos/build'
> + docker rmi mesos-1508815888-26887
> Untagged: mesos-1508815888-26887:latest
> Deleted: sha256:4d62ea553e773d4f39ff3a898b01bd
> 9cae2886cef92f1452cdf2d4ae7f3dec61
> Deleted: sha256:3b0fc3cc5564a99a8fb9d77c83cfeb
> 58217f7e7c5b91692ceb36db6a5064f126
> Deleted: sha256:5fc10490f239c5ebf2efb239a58081
> 53aa919d32ef81980e3ca336c971ae7ab1
> Deleted: sha256:c498574654714f603a59012712fa65
> 97062bb8ee10bc09ca5c7292c0fe561144
> Deleted: sha256:d5229c44dd43d7ee90cfbac08fc1c5
> 6d9cdd66a855f1d99b94fba8ce299db261
> Deleted: sha256:b76ffb7d7cd9f2af4fd703b32db785
> 01e401e61832aa50a673169b8835f2ffe5
> Deleted: sha256:d4fe1ef960025098e428e29b1b27b7
> 00bec19f59b5a85620b906f0a54f24da09
> Deleted: sha256:65f8f75b91333283e322648a87be16
> 8ca0c97de9e41894f5ddf07999e2c8b82d
> Deleted: sha256:8c8c04e7f0e51a67a2e7ffb14023cc
> cb21cad9806e6e51358d6e7cf80c8202ef
> Deleted: sha256:045c8ca3bcf6e06cbc1ad882723bc6
> e5dc83bc908017bbd088204e2fd71d8be3
> Deleted: sha256:158c679d77e50bbc45deb6adc0de6c
> 49be56c0b9d123c49adc88d7517afe21cc
> Deleted: sha256:0500f068e6eda8a463a56bce531924
> c8d07752355a7a2cd735514a45f478a203
> Deleted: sha256:726d2dfe461874ea64245c5c914327
> 4c3533c7ee902ed9ab8eb6c1ac896594e9
> Deleted: sha256:e0d7992dcbf4f3c38122fc771b00fa
> 1adee6b897b6d40b99e97b1dd689e9bb34
> Deleted: sha256:c9104c2aa37aa20b38c19a7983fd1d
> 384232b60fced9255d526cbd6579c716dd
> Deleted: sha256:e0d0738c6d13d79edccc3e5c324e10
> f3ab35da66d3d8f66a02a816c6a1e4bcfe
> Deleted: sha256:ced4af9c481a3d500a3aa51afa6efb
> 709afc6b412002cbaf2bbd20b5036a0aad
> Deleted: sha256:4c7f09ddbaeb96e7f1e0a157fb4564
> 30d927ab4b7c64405c6770d3b7d3182cf6
> Deleted: sha256:de4882cacdce27c67fc7caf0137c1b
> d1a02beed39f497f45c84924133dc9f2a3
> Deleted: sha256:423513bf19a297f5c34b86126e05a7
> d5d6ee1db6a3a2c1ed17af6003b1f02b1a
> Deleted: sha256:c2a1bc31516401deec262e14aeb2d3
> d1e1ed790c818b3d7c9792e9c75ccdd405
> Deleted: sha256:ce12f227c8b07fce2620b446f1b394
> 667983a484a3a75aabe438f578cbf0ec13
> Deleted: sha256:3882504ff4592a23ec241b8bf28dff
> 41ab2b2cfffab7ac4f5f18eab580d1b1e2
> Deleted: sha256:30b45c476d6a95a5ccce556a64c2a5
> 676dc122654020bea141e91c3022ac9cc8
> Deleted: sha256:a69321fba53e9ac063b6f19bd6da89
> 717daa60f466d8bdf1191fa81d52049706
> Deleted: sha256:38b487206307d129dbe747cbc848ec
> a09ecaef6dc83526273e21f26115bdfbf6
> Deleted: sha256:e7d0b9c4fa24a24efcaededd1dfac3
> 3d98889874816260241bda944ed7a7ef5c
> Deleted: sha256:19abba379dfa35cf4961480672ba2b
> f0c8a0518bc656774cdba4b9774a4a9e0b
> Build step 'Execute shell' marked build as failure
>