[
https://issues.apache.org/jira/browse/MESOS-6356?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16135596#comment-16135596
]
Vinod Kone commented on MESOS-6356:
-----------------------------------
Saw this recently on ASF CI
{code}
[ RUN ]
DiskResource/PersistentVolumeTest.SharedPersistentVolumeRescindOnDestroy/1
I0818 23:47:17.343003 2025 cluster.cpp:162] Creating default 'local' authorizer
I0818 23:47:17.346223 8074 master.cpp:442] Master
233c4092-ae37-4948-b072-16dc81f579c6 (629d22a490b3) started on 172.17.0.2:48361
I0818 23:47:17.346254 8074 master.cpp:444] Flags at startup: --acls=""
--agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
--allocation_interval="1secs" --all
ocator="HierarchicalDRF" --authenticate_agents="true"
--authenticate_frameworks="true" --authenticate_http_frameworks="true"
--authenticate_http_readonly="true" --authentica
te_http_readwrite="true" --authenticators="crammd5" --authorizers="local"
--credentials="/tmp/13CNgR/credentials" --filter_gpu_resources="true"
--framework_sorter="drf" --he
lp="false" --hostname_lookup="true" --http_authenticators="basic"
--http_framework_authenticators="basic" --initialize_driver_logging="true"
--log_auto_initialize="true" --l
ogbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5"
--max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
--max_unreachable_tasks_per_fra
mework="1000" --port="5050" --quiet="false"
--recovery_agent_removal_limit="100%" --registry="in_memory"
--registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --r
egistry_max_agent_age="2weeks" --registry_max_agent_count="102400"
--registry_store_timeout="100secs" --registry_strict="false"
--root_submissions="true" --user_sorter="drf"
--version="false" --webui_dir="/usr/local/share/mesos/webui"
--work_dir="/tmp/13CNgR/master" --zk_session_timeout="10secs"
I0818 23:47:17.346606 8074 master.cpp:494] Master only allowing authenticated
frameworks to register
I0818 23:47:17.346616 8074 master.cpp:508] Master only allowing authenticated
agents to register
I0818 23:47:17.346621 8074 master.cpp:521] Master only allowing authenticated
HTTP frameworks to register
I0818 23:47:17.346627 8074 credentials.hpp:37] Loading credentials for
authentication from '/tmp/13CNgR/credentials'
I0818 23:47:17.346974 8074 master.cpp:566] Using default 'crammd5'
authenticator
I0818 23:47:17.347167 8074 http.cpp:1026] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readonly'
I0818 23:47:17.347360 8074 http.cpp:1026] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readwrite'
I0818 23:47:17.347555 8074 http.cpp:1026] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-scheduler'
I0818 23:47:17.347728 8074 master.cpp:646] Authorization enabled
I0818 23:47:17.348001 8075 hierarchical.cpp:171] Initialized hierarchical
allocator process
I0818 23:47:17.348139 8078 whitelist_watcher.cpp:77] No whitelist given
I0818 23:47:17.351358 8081 master.cpp:2163] Elected as the leading master!
I0818 23:47:17.351392 8081 master.cpp:1702] Recovering from registrar
I0818 23:47:17.351549 8072 registrar.cpp:347] Recovering registrar
I0818 23:47:17.352370 8072 registrar.cpp:391] Successfully fetched the
registry (0B) in 0ns
I0818 23:47:17.352509 8072 registrar.cpp:495] Applied 1 operations in 33379ns;
attempting to update the registry
I0818 23:47:17.353128 8072 registrar.cpp:552] Successfully updated the
registry in 0ns
I0818 23:47:17.353251 8072 registrar.cpp:424] Successfully recovered registrar
I0818 23:47:17.353765 8073 master.cpp:1801] Recovered 0 agents from the
registry (129B); allowing 10mins for agents to re-register
I0818 23:47:17.353822 8071 hierarchical.cpp:209] Skipping recovery of
hierarchical allocator: nothing to recover
I0818 23:47:17.359251 2025 process.cpp:3228] Attempting to spawn already
spawned process [email protected]:48361
I0818 23:47:17.360659 2025 containerizer.cpp:246] Using isolation:
posix/cpu,posix/mem,filesystem/posix,network/cni,environment_secret
W0818 23:47:17.361210 2025 backend.cpp:76] Failed to create 'aufs' backend:
AufsBackend requires root privileges
W0818 23:47:17.361362 2025 backend.cpp:76] Failed to create 'bind' backend:
BindBackend requires root privileges
I0818 23:47:17.361393 2025 provisioner.cpp:255] Using default backend 'copy'
I0818 23:47:17.363803 2025 cluster.cpp:448] Creating default 'local' authorizer
I0818 23:47:17.366044 8070 slave.cpp:250] Mesos agent started on
(779)@172.17.0.2:48361
I0818 23:47:17.366066 8070 slave.cpp:251] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_kelFSo/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_SharedPersistentVolumeRescindOnDestroy_1_kelFSo/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_SharedPersistentVolumeRescindOnDestroy_1_kelFSo/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_SharedPersistentVolumeRescindOnDestroy_1_kelFSo/executor_secret_key"
--executor_shutdown_grace_period="5secs" --fetch:
er_cache_dir="/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_kelFSo/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_SharedPersistentVolumeRescindOnDestroy_1_kelFSo/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_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2\/disk1"},"type":"PATH"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"},{"disk":{"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2\/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_SharedPersistentVolumeRescindOnDestroy_1_kelFSo"
--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_SharedPersistentVolumeRescindOnDestroy_1_37IbFd"
I0818 23:47:17.366636 8070 credentials.hpp:86] Loading credential for
authentication from
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_kelFSo/credential'
I0818 23:47:17.366827 8070 slave.cpp:283] Agent using credential for:
test-principal
I0818 23:47:17.366847 8070 credentials.hpp:37] Loading credentials for
authentication from
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_kelFSo/http_credentials'
I0818 23:47:17.366904 2025 process.cpp:3228] Attempting to spawn already
spawned process [email protected]:48361
I0818 23:47:17.367192 8070 http.cpp:1026] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-executor'
I0818 23:47:17.367347 8070 http.cpp:1047] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-executor'
I0818 23:47:17.367645 8070 http.cpp:1026] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
I0818 23:47:17.367770 8070 http.cpp:1047] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readonly'
I0818 23:47:17.368037 8070 http.cpp:1026] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readwrite'
I0818 23:47:17.368124 2025 sched.cpp:232] Version: 1.4.0
I0818 23:47:17.368161 8070 http.cpp:1047] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readwrite'
I0818 23:47:17.368881 8082 sched.cpp:336] New master detected at
[email protected]:48361
I0818 23:47:17.369005 8082 sched.cpp:407] Authenticating with master
[email protected]:48361
I0818 23:47:17.369027 8082 sched.cpp:414] Using default CRAM-MD5 authenticatee
I0818 23:47:17.369374 8072 authenticatee.cpp:121] Creating new client SASL
connection
I0818 23:47:17.369431 8071 hierarchical.cpp:1925] No allocations performed
I0818 23:47:17.369480 8071 hierarchical.cpp:1468] Performed allocation for 0
agents in 98694ns
I0818 23:47:17.369740 8081 master.cpp:7837] Authenticating
[email protected]:48361
I0818 23:47:17.370070 8079 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1427)@172.17.0.2:48361
I0818 23:47:17.370486 8084 authenticator.cpp:98] Creating new server SASL
connection
I0818 23:47:17.370851 8085 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I0818 23:47:17.370878 8085 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0818 23:47:17.370973 8085 authenticator.cpp:204] Received SASL authentication
start
I0818 23:47:17.371031 8085 authenticator.cpp:326] Authentication requires more
steps
I0818 23:47:17.371119 8078 authenticatee.cpp:259] Received SASL authentication
step
I0818 23:47:17.371419 8077 authenticator.cpp:232] Received SASL authentication
step
I0818 23:47:17.371448 8077 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '629d22a490b3' server FQDN: '629d22a490b3'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I0818 23:47:17.371456 8077 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I0818 23:47:17.371497 8077 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0818 23:47:17.371626 8077 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '629d22a490b3' server FQDN: '629d22a490b3'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
I0818 23:47:17.371639 8077 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0818 23:47:17.371644 8077 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0818 23:47:17.371655 8077 authenticator.cpp:318] Authentication success
I0818 23:47:17.371889 8080 authenticatee.cpp:299] Authentication success
I0818 23:47:17.371887 8074 master.cpp:7867] Successfully authenticated
principal 'test-principal' at
[email protected]:48361
I0818 23:47:17.372042 8083 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1427)@172.17.0.2:48361
I0818 23:47:17.372247 8073 sched.cpp:513] Successfully authenticated with
master [email protected]:48361
I0818 23:47:17.372267 8073 sched.cpp:836] Sending SUBSCRIBE call to
[email protected]:48361
I0818 23:47:17.372397 8073 sched.cpp:869] Will retry registration in
898.661147ms if necessary
I0818 23:47:17.372603 8081 master.cpp:2894] Received SUBSCRIBE call for
framework 'default' at
[email protected]:48361
I0818 23:47:17.372642 8079 sched.cpp:836] Sending SUBSCRIBE call to
[email protected]:48361
I0818 23:47:17.372712 8081 master.cpp:2228] Authorizing framework principal
'test-principal' to receive offers for roles '{ default-role }'
I0818 23:47:17.372776 8079 sched.cpp:869] Will retry registration in
2.662465454secs if necessary
I0818 23:47:17.373070 8081 master.cpp:2894] Received SUBSCRIBE call for
framework 'default' at
[email protected]:48361
I0818 23:47:17.373144 8081 master.cpp:2228] Authorizing framework principal
'test-principal' to receive offers for roles '{ default-role }'
I0818 23:47:17.373378 8081 master.cpp:2974] Subscribing framework default with
checkpointing disabled and capabilities [ RESERVATION_REFINEMENT,
SHARED_RESOURCES ]
I0818 23:47:17.373296 8070 slave.cpp:565] 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_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2\/disk1"},"type":"PATH"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"},{"disk":{"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2\/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"}]
I0818 23:47:17.373950 8070 slave.cpp:573] Agent attributes: [ ]
I0818 23:47:17.373963 8070 slave.cpp:582] Agent hostname: 629d22a490b3
I0818 23:47:17.374055 8078 sched.cpp:759] Framework registered with
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.374070 8081 master.cpp:2974] Subscribing framework default with
checkpointing disabled and capabilities [ RESERVATION_REFINEMENT,
SHARED_RESOURCES ]
I0818 23:47:17.374130 8078 sched.cpp:773] Scheduler::registered took 49214ns
I0818 23:47:17.374142 8081 master.cpp:2984] Framework
233c4092-ae37-4948-b072-16dc81f579c6-0000 (default) at
[email protected]:48361 already
subscribed, resending acknowledgement
I0818 23:47:17.374251 8075 hierarchical.cpp:303] Added framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.374174 8074 status_update_manager.cpp:177] Pausing sending
status updates
I0818 23:47:17.374440 8076 sched.cpp:746] Ignoring framework registered
message because the driver is already connected!
I0818 23:47:17.374459 8075 hierarchical.cpp:1925] No allocations performed
I0818 23:47:17.374491 8075 hierarchical.cpp:2015] No inverse offers to send
out!
I0818 23:47:17.374533 8075 hierarchical.cpp:1468] Performed allocation for 0
agents in 114808ns
I0818 23:47:17.375768 8073 state.cpp:64] Recovering state from
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_37IbFd/meta'
I0818 23:47:17.376118 8077 status_update_manager.cpp:203] Recovering status
update manager
I0818 23:47:17.376334 8078 containerizer.cpp:609] Recovering containerizer
I0818 23:47:17.378101 8077 provisioner.cpp:416] Provisioner recovery complete
I0818 23:47:17.378566 8081 slave.cpp:6210] Finished recovery
I0818 23:47:17.379065 8081 slave.cpp:6392] Querying resource estimator for
oversubscribable resources
I0818 23:47:17.379379 8082 status_update_manager.cpp:177] Pausing sending
status updates
I0818 23:47:17.379416 8078 slave.cpp:971] New master detected at
[email protected]:48361
I0818 23:47:17.379499 8078 slave.cpp:1006] Detecting new master
I0818 23:47:17.379763 8078 slave.cpp:6406] Received oversubscribable resources
{} from the resource estimator
I0818 23:47:17.379866 8078 slave.cpp:1033] Authenticating with master
[email protected]:48361
I0818 23:47:17.379947 8078 slave.cpp:1044] Using default CRAM-MD5 authenticatee
I0818 23:47:17.380190 8071 authenticatee.cpp:121] Creating new client SASL
connection
I0818 23:47:17.380497 8071 master.cpp:7837] Authenticating
slave(779)@172.17.0.2:48361
I0818 23:47:17.380650 8084 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1428)@172.17.0.2:48361
I0818 23:47:17.380941 8079 authenticator.cpp:98] Creating new server SASL
connection
I0818 23:47:17.381181 8070 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I0818 23:47:17.381206 8070 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0818 23:47:17.381331 8073 authenticator.cpp:204] Received SASL authentication
start
I0818 23:47:17.381397 8073 authenticator.cpp:326] Authentication requires more
steps
I0818 23:47:17.381525 8075 authenticatee.cpp:259] Received SASL authentication
step
I0818 23:47:17.381652 8072 authenticator.cpp:232] Received SASL authentication
step
I0818 23:47:17.381685 8072 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '629d22a490b3' server FQDN: '629d22a490b3'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I0818 23:47:17.381695 8072 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I0818 23:47:17.381728 8072 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0818 23:47:17.381744 8072 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '629d22a490b3' server FQDN: '629d22a490b3'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
I0818 23:47:17.381752 8072 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0818 23:47:17.381757 8072 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0818 23:47:17.381773 8072 authenticator.cpp:318] Authentication success
I0818 23:47:17.381940 8080 authenticatee.cpp:299] Authentication success
I0818 23:47:17.381971 8077 master.cpp:7867] Successfully authenticated
principal 'test-principal' at slave(779)@172.17.0.2:48361
I0818 23:47:17.382017 8072 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1428)@172.17.0.2:48361
I0818 23:47:17.382318 8083 slave.cpp:1128] Successfully authenticated with
master [email protected]:48361
I0818 23:47:17.382617 8083 slave.cpp:1572] Will retry registration in
9.640564ms if necessary
I0818 23:47:17.382906 8085 master.cpp:5712] Received register agent message
from slave(779)@172.17.0.2:48361 (629d22a490b3)
I0818 23:47:17.383141 8085 master.cpp:3803] Authorizing agent with principal
'test-principal'
I0818 23:47:17.383563 8071 master.cpp:5772] Authorized registration of agent
at slave(779)@172.17.0.2:48361 (629d22a490b3)
I0818 23:47:17.383677 8071 master.cpp:5865] Registering agent at
slave(779)@172.17.0.2:48361 (629d22a490b3) with id
233c4092-ae37-4948-b072-16dc81f579c6-S0
I0818 23:47:17.384215 8079 registrar.cpp:495] Applied 1 operations in 66536ns;
attempting to update the registry
I0818 23:47:17.384910 8079 registrar.cpp:552] Successfully updated the
registry in 0ns
I0818 23:47:17.385152 8082 master.cpp:5912] Admitted agent
233c4092-ae37-4948-b072-16dc81f579c6-S0 at slave(779)@172.17.0.2:48361
(629d22a490b3)
I0818 23:47:17.385951 8074 slave.cpp:4887] Received ping from
slave-observer(707)@172.17.0.2:48361
I0818 23:47:17.386142 8074 slave.cpp:1174] Registered with master
[email protected]:48361; given agent ID 233c4092-ae37-4948-b072-16dc81f579c6-S0
I0818 23:47:17.386344 8083 status_update_manager.cpp:184] Resuming sending
status updates
I0818 23:47:17.386618 8074 slave.cpp:1194] Checkpointing SlaveInfo to
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_37IbFd/meta/slaves/233c4092-ae37-4948-b072-16dc81f579c6-S0/slave.info'
I0818 23:47:17.386634 8072 hierarchical.cpp:593] Added agent
233c4092-ae37-4948-b072-16dc81f579c6-S0 (629d22a490b3) with cpus:2; mem:2048;
disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk1]:2048;
disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk2]:2048;
ports:[31000-32000] (allocated: {})
I0818 23:47:17.386054 8082 master.cpp:5943] Registered agent
233c4092-ae37-4948-b072-16dc81f579c6-S0 at slave(779)@172.17.0.2:48361
(629d22a490b3) with
[{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":2048.0},"type":"SCALAR"},{"disk":{"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2\/disk1"},"type":"PATH"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"type":"SCALAR"},{"disk":{"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2\/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"}]
I0818 23:47:17.387122 8074 slave.cpp:1232] Forwarding total oversubscribed
resources {}
I0818 23:47:17.387284 8074 master.cpp:6688] Received update of agent
233c4092-ae37-4948-b072-16dc81f579c6-S0 at slave(779)@172.17.0.2:48361
(629d22a490b3) with total oversubscribed resources {}
I0818 23:47:17.388113 8072 hierarchical.cpp:2015] No inverse offers to send
out!
I0818 23:47:17.388150 8072 hierarchical.cpp:1468] Performed allocation for 1
agents in 1.326338ms
I0818 23:47:17.388335 8072 hierarchical.cpp:660] Agent
233c4092-ae37-4948-b072-16dc81f579c6-S0 (629d22a490b3) updated with total
resources cpus:2; mem:2048; disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk1]:2048;
disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk2]:2048;
ports:[31000-32000]
I0818 23:47:17.389010 8084 master.cpp:7667] Sending 1 offers to framework
233c4092-ae37-4948-b072-16dc81f579c6-0000 (default) at
[email protected]:48361
I0818 23:47:17.389569 8084 sched.cpp:933] Scheduler::resourceOffers took
110044ns
I0818 23:47:17.392189 8075 master.cpp:9164] Removing offer
233c4092-ae37-4948-b072-16dc81f579c6-O0
I0818 23:47:17.392400 8075 master.cpp:4153] Processing ACCEPT call for offers:
[ 233c4092-ae37-4948-b072-16dc81f579c6-O0 ] on agent
233c4092-ae37-4948-b072-16dc81f579c6-S0 at slave(779)@172.17.0.2:48361
(629d22a490b3) for framework 233c4092-ae37-4948-b072-16dc81f579c6-0000
(default) at [email protected]:48361
I0818 23:47:17.392580 8075 master.cpp:3723] 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_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id2","principal":"test-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2\/disk2"},"type":"PATH"},"volume":{"container_path":"path2","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"}]'
I0818 23:47:17.393362 8075 master.cpp:3530] Authorizing framework principal
'test-principal' to launch task 0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf
I0818 23:47:17.395423 8075 master.cpp:4576] Applying CREATE operation for
volumes
[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id2","principal":"test-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2\/disk2"},"type":"PATH"},"volume":{"container_path":"path2","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"}]
from framework 233c4092-ae37-4948-b072-16dc81f579c6-0000 (default) at
[email protected]:48361 to agent
233c4092-ae37-4948-b072-16dc81f579c6-S0 at slave(779)@172.17.0.2:48361
(629d22a490b3)
I0818 23:47:17.396441 8075 master.cpp:9110] Sending updated checkpointed
resources disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk1,id1:path1]<SHARED>:2048<1>;
disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk2,id2:path2]<SHARED>:2048<1>
to agent 233c4092-ae37-4948-b072-16dc81f579c6-S0 at
slave(779)@172.17.0.2:48361 (629d22a490b3)
I0818 23:47:17.397655 8075 master.cpp:9724] Adding task
0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf with resources
[{"allocation_info":{"role":"default-role"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"name":"mem","scalar":{"value":128.0},"type":"SCALAR"}]
on agent 233c4092-ae37-4948-b072-16dc81f579c6-S0 at
slave(779)@172.17.0.2:48361 (629d22a490b3)
I0818 23:47:17.398056 8075 master.cpp:4816] Launching task
0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000 (default) at
[email protected]:48361 with resources
[{"allocation_info":{"role":"default-role"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"name":"mem","scalar":{"value":128.0},"type":"SCALAR"}]
on agent 233c4092-ae37-4948-b072-16dc81f579c6-S0 at
slave(779)@172.17.0.2:48361 (629d22a490b3)
I0818 23:47:17.398317 8074 slave.cpp:3449] Updated checkpointed resources from
{} to disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk1,id1:path1]<SHARED>:2048<1>;
disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk2,id2:path2]<SHARED>:2048<1>
I0818 23:47:17.398833 8074 slave.cpp:1701] Got assigned task
'0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf' for framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.399495 8074 slave.cpp:1982] Authorizing task
'0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf' for framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.399545 8074 slave.cpp:6709] Authorizing framework principal
'test-principal' to launch task 0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf
I0818 23:47:17.400400 8070 slave.cpp:2169] Launching task
'0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf' for framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.401100 8070 paths.cpp:578] Trying to chown
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_37IbFd/slaves/233c4092-ae37-4948-b072-16dc81f579c6-S0/frameworks/233c4092-ae37-4948-b072-16dc81f579c6-0000/executors/0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf/runs/1aa9123a-d94d-49db-9722-667a2101217c'
to user 'mesos'
I0818 23:47:17.401383 8070 slave.cpp:7165] Launching executor
'0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf' of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000 with resources
[{"allocation_info":{"role":"default-role"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"name":"mem","scalar":{"value":32:
.0},"type":"SCALAR"}] in work directory
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_37IbFd/slaves/233c4092-ae37-4948-b072-16dc81f579c6-S0/frameworks/233c4092-ae37-4948-b072-16dc81f579c6-0000/executors/0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf/runs/1aa9123a-d94d-49db-9722-667a2101217c'
I0818 23:47:17.402406 8070 slave.cpp:2398] Queued task
'0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf' for executor
'0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf' of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.402496 8070 slave.cpp:924] Successfully attached file
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_37IbFd/slaves/233c4092-ae37-4948-b072-16dc81f579c6-S0/frameworks/233c4092-ae37-4948-b072-16dc81f579c6-0000/executors/0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf/runs/1aa9123a-d94d-49db-9722-667a2101217c'
I0818 23:47:17.402480 8072 hierarchical.cpp:887] Updated allocation of
framework 233c4092-ae37-4948-b072-16dc81f579c6-0000 on agent
233c4092-ae37-4948-b072-16dc81f579c6-S0 from cpus(allocated: default-role):2;
mem(allocated: default-role):2048; disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk1]:2048;
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/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_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk1,id1:path1]<SHARED>:2048<1>;
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk2,id2:path2]<SHARED>:2048<1>
I0818 23:47:17.402549 8070 slave.cpp:924] Successfully attached file
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_37IbFd/slaves/233c4092-ae37-4948-b072-16dc81f579c6-S0/frameworks/233c4092-ae37-4948-b072-16dc81f579c6-0000/executors/0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf/runs/1aa9123a-d94d-49db-9722-667a2101217c'
I0818 23:47:17.402880 8070 slave.cpp:2856] Launching container
1aa9123a-d94d-49db-9722-667a2101217c for executor
'0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf' of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.403189 8077 containerizer.cpp:1083] Starting container
1aa9123a-d94d-49db-9722-667a2101217c
I0818 23:47:17.403844 8077 containerizer.cpp:2673] Transitioning the state of
container 1aa9123a-d94d-49db-9722-667a2101217c from PROVISIONING to PREPARING
I0818 23:47:17.404474 8072 hierarchical.cpp:1152] Recovered cpus(allocated:
default-role):1; mem(allocated: default-role):1920; ports(allocated:
default-role):[31000-32000]; disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk1,id1:path1]<SHARED>:2048<1>;
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk2,id2:path2]<SHARED>:2048<1>
(total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk1,id1:path1]<SHARED>:2048<1>;
disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk2,id2:path2]<SHARED>:2048<1>,
allocated: cpus(allocated: default-role):1; mem(allocated: default-role):128)
on agent 233c4092-ae37-4948-b072-16dc81f579c6-S0 from framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.408231 8071 containerizer.cpp:1657] Launching
'mesos-containerizer' with flags '--help="false"
--launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=\/mesos\/build\/src"],"shell":false,"value":"\/mesos\/build\/src\/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.2:48361"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_37IbFd\/slaves\/233c4092-ae37-4948-b072-16dc81f579c6-S0\/frameworks\/233c4092-ae37-4948-b072-16dc81f579c6-0000\/executors\/0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf\/runs\/1aa9123a-d94d-49db-9722-667a2101217c"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiIxYWE5MTIzYS1kOTRkLTQ5ZGItOTcyMi02NjdhMjEwMTIxN2MiLCJlaWQiOiIwYTAzOTc4YS1iMmQ3LTRlNzQtODliYy03ZWY2ZjA1YTRlYWYiLCJmaWQiOiIyMzNjNDA5Mi1hZTM3LTQ5NDgtYjA3Mi0xNmRjODFmNTc5YzYtMDAwMCJ9.soI22VzlscyaQ0XWjQsqh9vYsA_lKmNNfYii-FOR9QU"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"233c4092-ae37-4948-b072-16dc81f579c6-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"233c4092-ae37-4948-b072-16dc81f579c6-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(779)@172.17.0.2:48361"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_37IbFd\/slaves\/233c4092-ae37-4948-b072-16dc81f579c6-S0\/frameworks\/233c4092-ae37-4948-b072-16dc81f579c6-0000\/executors\/0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf\/runs\/1aa9123a-d94d-49db-9722-667a2101217c"}]},"task_environment":{},"user":"mesos","working_directory":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_37IbFd\/slaves\/233c4092-ae37-4948-b072-16dc81f579c6-S0\/frameworks\/233c4092-ae37-4948-b072-16dc81f579c6-0000\/executors\/0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf\/runs\/1aa9123a-d94d-49db-9722-667a2101217c"}"
--pipe_read="10" --pipe_write="13"
--runtime_directory="/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_kelFSo/containers/1aa9123a-d94d-49db-9722-667a2101217c"
--unshare_namespace_mnt="false"'
I0818 23:47:17.411105 8071 launcher.cpp:140] Forked child with pid '8248' for
container '1aa9123a-d94d-49db-9722-667a2101217c'
I0818 23:47:17.411710 8071 containerizer.cpp:2673] Transitioning the state of
container 1aa9123a-d94d-49db-9722-667a2101217c from PREPARING to ISOLATING
I0818 23:47:17.413981 8081 containerizer.cpp:2673] Transitioning the state of
container 1aa9123a-d94d-49db-9722-667a2101217c from ISOLATING to FETCHING
I0818 23:47:17.414186 8076 fetcher.cpp:379] Starting to fetch URIs for
container: 1aa9123a-d94d-49db-9722-667a2101217c, directory:
/tmp/DiskResource_PersistentVolumeTest_Sh:
aredPersistentVolumeRescindOnDestroy_1_37IbFd/slaves/233c4092-ae37-4948-b072-16dc81f579c6-S0/frameworks/233c4092-ae37-4948-b072-16dc81f579c6-0000/executors/0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf/runs/1aa9123a-d94d-49db-9722-667a2101217c
I0818 23:47:17.415243 8072 containerizer.cpp:2673] Transitioning the state of
container 1aa9123a-d94d-49db-9722-667a2101217c from FETCHING to RUNNING
I0818 23:47:17.416244 2025 process.cpp:3228] Attempting to spawn already
spawned process [email protected]:48361
I0818 23:47:17.416993 2025 sched.cpp:232] Version: 1.4.0
I0818 23:47:17.417681 8071 sched.cpp:336] New master detected at
[email protected]:48361
I0818 23:47:17.417817 8071 sched.cpp:407] Authenticating with master
[email protected]:48361
I0818 23:47:17.417835 8071 sched.cpp:414] Using default CRAM-MD5 authenticatee
I0818 23:47:17.418215 8070 authenticatee.cpp:121] Creating new client SASL
connection
I0818 23:47:17.418540 8070 master.cpp:7837] Authenticating
[email protected]:48361
I0818 23:47:17.418742 8079 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1429)@172.17.0.2:48361
I0818 23:47:17.419020 8073 authenticator.cpp:98] Creating new server SASL
connection
I0818 23:47:17.419248 8081 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I0818 23:47:17.419275 8081 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0818 23:47:17.419390 8076 authenticator.cpp:204] Received SASL authentication
start
I0818 23:47:17.419443 8076 authenticator.cpp:326] Authentication requires more
steps
I0818 23:47:17.419533 8076 authenticatee.cpp:259] Received SASL authentication
step
I0818 23:47:17.419703 8077 authenticator.cpp:232] Received SASL authentication
step
I0818 23:47:17.419725 8077 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '629d22a490b3' server FQDN: '629d22a490b3'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I0818 23:47:17.419734 8077 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I0818 23:47:17.419766 8077 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0818 23:47:17.419782 8077 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '629d22a490b3' server FQDN: '629d22a490b3'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
I0818 23:47:17.419790 8077 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0818 23:47:17.419795 8077 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0818 23:47:17.419807 8077 authenticator.cpp:318] Authentication success
I0818 23:47:17.419900 8082 authenticatee.cpp:299] Authentication success
I0818 23:47:17.419998 8080 master.cpp:7867] Successfully authenticated
principal 'test-principal' at
[email protected]:48361
I0818 23:47:17.420184 8082 sched.cpp:513] Successfully authenticated with
master [email protected]:48361
I0818 23:47:17.420200 8082 sched.cpp:836] Sending SUBSCRIBE call to
[email protected]:48361
I0818 23:47:17.420305 8082 sched.cpp:869] Will retry registration in
975.715663ms if necessary
I0818 23:47:17.420418 8077 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1429)@172.17.0.2:48361
I0818 23:47:17.420497 8071 master.cpp:2894] Received SUBSCRIBE call for
framework 'default' at
[email protected]:48361
I0818 23:47:17.420580 8071 master.cpp:2228] Authorizing framework principal
'test-principal' to receive offers for roles '{ default-role }'
I0818 23:47:17.421072 8073 master.cpp:2974] Subscribing framework default with
checkpointing disabled and capabilities [ RESERVATION_REFINEMENT,
SHARED_RESOURCES ]
I0818 23:47:17.421490 8076 sched.cpp:759] Framework registered with
233c4092-ae37-4948-b072-16dc81f579c6-0001
I0818 23:47:17.421533 8076 sched.cpp:773] Scheduler::registered took 22750ns
I0818 23:47:17.421538 8081 hierarchical.cpp:303] Added framework
233c4092-ae37-4948-b072-16dc81f579c6-0001
I0818 23:47:17.425995 8081 hierarchical.cpp:2015] No inverse offers to send
out!
I0818 23:47:17.426059 8081 hierarchical.cpp:1468] Performed allocation for 1
agents in 4.370942ms
I0818 23:47:17.426702 8072 master.cpp:7667] Sending 1 offers to framework
233c4092-ae37-4948-b072-16dc81f579c6-0001 (default) at
[email protected]:48361
I0818 23:47:17.427232 8085 sched.cpp:933] Scheduler::resourceOffers took
99917ns
I0818 23:47:17.428076 8083 master.cpp:5296] Processing KILL call for task
'0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf' of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000 (default) at
[email protected]:48361
I0818 23:47:17.428143 8083 master.cpp:5369] Telling agent
233c4092-ae37-4948-b072-16dc81f579c6-S0 at slave(779)@172.17.0.2:48361
(629d22a490b3) to kill task 0a03978a-b2d7-4:
e74-89bc-7ef6f05a4eaf of framework 233c4092-ae37-4948-b072-16dc81f579c6-0000
(default) at [email protected]:48361
I0818 23:47:17.428319 8074 slave.cpp:2929] Asked to kill task
0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
W0818 23:47:17.428365 8074 slave.cpp:3017] Transitioning the state of task
0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000 to TASK_KILLED because the executor
is not registered
I0818 23:47:17.428458 8074 slave.cpp:4345] Handling status update TASK_KILLED
(UUID: 1993ba76-6534-4f86-a1c9-f1d304a8510d) for task
0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000 from @0.0.0.0:0
I0818 23:47:17.431260 8073 status_update_manager.cpp:323] Received status
update TASK_KILLED (UUID: 1993ba76-6534-4f86-a1c9-f1d304a8510d) for task
0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.431300 8073 status_update_manager.cpp:500] Creating
StatusUpdate stream for task 0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.431816 8073 status_update_manager.cpp:377] Forwarding update
TASK_KILLED (UUID: 1993ba76-6534-4f86-a1c9-f1d304a8510d) for task
0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000 to the agent
I0818 23:47:17.432013 8072 slave.cpp:4797] Forwarding the update TASK_KILLED
(UUID: 1993ba76-6534-4f86-a1c9-f1d304a8510d) for task
0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000 to [email protected]:48361
I0818 23:47:17.432194 8072 slave.cpp:4691] Status update manager successfully
handled status update TASK_KILLED (UUID: 1993ba76-6534-4f86-a1c9-f1d304a8510d)
for task 0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.432371 8085 master.cpp:6846] Status update TASK_KILLED (UUID:
1993ba76-6534-4f86-a1c9-f1d304a8510d) for task
0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000 from agent
233c4092-ae37-4948-b072-16dc81f579c6-S0 at slave(779)@172.17.0.2:48361
(629d22a490b3)
I0818 23:47:17.432416 8085 master.cpp:6908] Forwarding status update
TASK_KILLED (UUID: 1993ba76-6534-4f86-a1c9-f1d304a8510d) for task
0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.432572 8085 master.cpp:8933] Updating the state of task
0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000 (latest state: TASK_KILLED, status
update state: TASK_KILLED)
I0818 23:47:17.432724 8081 sched.cpp:1041] Scheduler::statusUpdate took 21591ns
I0818 23:47:17.433100 8083 hierarchical.cpp:1152] Recovered cpus(allocated:
default-role):1; mem(allocated: default-role):128 (total: cpus:2; mem:2048;
ports:[31000-32000]; disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk1,id1:path1]<SHARED>:2048<1>;
disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk2,id2:path2]<SHARED>:2048<1>,
allocated: cpus(allocated: default-role):1; mem(allocated: default-role):1920;
ports(allocated: default-role):[31000-32000]; disk(allocated:
default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk1,id1:path1]<SHARED>:2048<1>;
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk2,id2:path2]<SHARED>:2048<1>)
on agent 233c4092-ae37-4948-b072-16dc81f579c6-S0 from framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.433140 8085 master.cpp:5477] Processing ACKNOWLEDGE call
1993ba76-6534-4f86-a1c9-f1d304a8510d for task
0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000 (default) at
[email protected]:48361 on agent
233c4092-ae37-4948-b072-16dc81f579c6-S0
I0818 23:47:17.433212 8085 master.cpp:9027] Removing task
0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf with resources
[{"allocation_info":{"role":"default-role"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"name":"mem","scalar":{"value":128.0},"type":"SCALAR"}]
of framework 233c4092-ae37-4948-b072-16dc81f579c6-0000 on agent
233c4092-ae37-4948-b072-16dc81f579c6-S0 at slave(779)@172.17.0.2:48361
(629d22a490b3)
I0818 23:47:17.433727 8085 status_update_manager.cpp:395] Received status
update acknowledgement (UUID: 1993ba76-6534-4f86-a1c9-f1d304a8510d) for task
0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.433845 8085 status_update_manager.cpp:531] Cleaning up status
update stream for task 0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.434142 8085 slave.cpp:3609] Status update manager successfully
handled status update acknowledgement (UUID:
1993ba76-6534-4f86-a1c9-f1d304a8510d) for task
0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.434187 8085 slave.cpp:7561] Completing task
0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf
I0818 23:47:17.436779 8077 hierarchical.cpp:2015] No inverse offers to send
out!
I0818 23:47:17.436822 8077 hierarchical.cpp:1468] Performed allocation for 1
agents in 1.546834ms
I0818 23:47:17.437381 8073 master.cpp:7667] Sending 1 offers to framework
233c4092-ae37-4948-b072-16dc81f579c6-0000 (default) at
[email protected]:48361
I0818 23:47:17.437865 8072 sched.cpp:933] Scheduler::resourceOffers took
107330ns
I0818 23:47:17.439997 8070 master.cpp:9164] Removing offer
233c4092-ae37-4948-b072-16dc81f579c6-O1
I0818 23:47:17.440122 8070 master.cpp:4153] Processing ACCEPT call for offers:
[ 233c4092-ae37-4948-b072-16dc81f579c6-O1 ] on agent
233c4092-ae37-4948-b072-16dc81f579c6-S0 at slave(779)@172.17.0.2:48361
(629d22a490b3) for framework 233c4092-ae37-4948-b072-16dc81f579c6-0001
(default) at [email protected]:48361
I0818 23:47:17.440301 8070 master.cpp:3775] Authorizing principal
'test-principal' to destroy volumes
'[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id2","principal":"test-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2\/disk2"},"type":"PATH"},"volume":{"container_path":"path2","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"}]'
I0818 23:47:17.442396 8078 master.cpp:9164] Removing offer
233c4092-ae37-4948-b072-16dc81f579c6-O2
I0818 23:47:17.442497 8071 sched.cpp:959] Rescinded offer
233c4092-ae37-4948-b072-16dc81f579c6-O2
I0818 23:47:17.442584 8071 sched.cpp:970] Scheduler::offerRescinded took
51347ns
I0818 23:47:17.442945 2025 sched.cpp:2021] Asked to stop the driver
I0818 23:47:17.443181 8082 hierarchical.cpp:1152] Recovered cpus(allocated:
default-role):1; mem(allocated: default-role):128; disk(allocated:
default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk1,id1:path1]<SHARED>:2048<1>;
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk2,id2:path2]<SHARED>:2048<1>
(total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk1,id1:path1]<SHARED>:2048<1>;
disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk2,id2:path2]<SHARED>:2048<1>,
allocated: cpus(allocated: default-role):1; mem(allocated: default-role):1920;
ports(allocated: default-role):[31000-32000]; disk(allocated:
default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk1,id1:path1]<SHARED>:2048<1>;
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk2,id2:path2]<SHARED>:2048<1>)
on agent 233c4092-ae37-4948-b072-16dc81f579c6-S0 from framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.443316 8082 sched.cpp:1203] Stopping framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.442981 8078 master.cpp:4657] Applying DESTROY operation for
volumes
[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id2","principal":"test-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2\/disk2"},"type":"PATH"},"volume":{"container_path":"path2","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"}]
from framework 233c4092-ae37-4948-b072-16dc81f579c6-0001 (default) at
[email protected]:48361 to agent
233c4092-ae37-4948-b072-16dc81f579c6-S0 at slave(779)@172.17.0.2:48361
(629d22a490b3)
I0818 23:47:17.443667 2025 sched.cpp:2021] Asked to stop the driver
I0818 23:47:17.443768 8078 master.cpp:9110] Sending updated checkpointed
resources {} to agent 233c4092-ae37-4948-b072-16dc81f579c6-S0 at
slave(779)@172.17.0.2:48361 (629d22a490b3)
I0818 23:47:17.443814 8072 sched.cpp:1203] Stopping framework
233c4092-ae37-4948-b072-16dc81f579c6-0001
I0818 23:47:17.444180 8078 master.cpp:8348] Processing TEARDOWN call for
framework 233c4092-ae37-4948-b072-16dc81f579c6-0000 (default) at
[email protected]:48361
I0818 23:47:17.444211 8078 master.cpp:8360] Removing framework
233c4092-ae37-4948-b072-16dc81f579c6-0000 (default) at
[email protected]:48361
I0818 23:47:17.444255 8078 master.cpp:3264] Deactivating framework
233c4092-ae37-4948-b072-16dc81f579c6-0000 (default) at
[email protected]:48361
I0818 23:47:17.444591 8073 slave.cpp:3514] Deleting persistent volume 'id1' at
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk1/volumes/roles/default-role/id1'
I0818 23:47:17.444712 8078 master.cpp:8348] Processing TEARDOWN call for
framework 233c4092-ae37-4948-b072-16dc81f579c6-0001 (default) at
[email protected]:48361
I0818 23:47:17.444763 8078 master.cpp:8360] Removing framework
233c4092-ae37-4948-b072-16dc81f579c6-0001 (default) at
[email protected]:48361
I0818 23:47:17.444809 8078 master.cpp:3264] Deactivating framework
233c4092-ae37-4948-b072-16dc81f579c6-0001 (default) at
[email protected]:48361
I0818 23:47:17.444978 8073 slave.cpp:3514] Deleting persistent volume 'id2' at
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk2/volumes/roles/default-role/id2'
I0818 23:47:17.445248 8073 slave.cpp:3449] Updated checkpointed resources from
disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk1,id1:path1]<SHARED>:2048<1>;
disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk2,id2:path2]<SHARED>:2048<1>
to {}
I0818 23:47:17.445375 8073 slave.cpp:3159] Asked to shut down framework
233c4092-ae37-4948-b072-16dc81f579c6-0000 by [email protected]:48361
I0818 23:47:17.445452 8073 slave.cpp:3184] Shutting down framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.445507 8073 slave.cpp:5651] Shutting down executor
'0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf' of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
W0818 23:47:17.445530 8073 slave.hpp:739] Unable to send event to executor
'0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf' of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000: unknown connection type
I0818 23:47:17.445678 8074 containerizer.cpp:2132] Destroying container
1aa9123a-d94d-49db-9722-667a2101217c in RUNNING state
I0818 23:47:17.445704 8074 containerizer.cpp:2673] Transitioning the state of
container 1aa9123a-d94d-49db-9722-667a2101217c from RUNNING to DESTROYING
I0818 23:47:17.445811 8073 slave.cpp:3159] Asked to shut down framework
233c4092-ae37-4948-b072-16dc81f579c6-0001 by [email protected]:48361
I0818 23:47:17.445932 8073 slave.cpp:3174] Cannot shut down unknown framework
233c4092-ae37-4948-b072-16dc81f579c6-0001
I0818 23:47:17.446066 8074 launcher.cpp:156] Asked to destroy container
1aa9123a-d94d-49db-9722-667a2101217c
I0818 23:47:17.448526 8072 hierarchical.cpp:887] Updated allocation of
framework 233c4092-ae37-4948-b072-16dc81f579c6-0001 on agent
233c4092-ae37-4948-b072-16dc81f579c6-S0 from cpus(allocated: default-role):1;
mem(allocated: default-role):1920; ports(allocated:
default-role):[31000-32000]; disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk1,id1:path1]<SHARED>:2048<1>;
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk2,id2:path2]<SHARED>:2048<1>
to cpus(allocated: default-role):1; mem(allocated: default-role):1920;
ports(allocated: default-role):[31000-32000]; disk(allocated:
default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk1]:2048;
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk2]:2048
I0818 23:47:17.449611 8072 hierarchical.cpp:1152] Recovered cpus(allocated:
default-role):1; mem(allocated: default-role):1920; ports(allocated:
default-role):[31000-32000]; disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk1]:2048;
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk2]:2048
(total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk1]:2048;
disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_MvBJr2/disk2]:2048,
allocated: {}) on agent 233c4092-ae37-4948-b072-16dc81f579c6-S0 from framework
233c4092-ae37-4948-b072-16dc81f579c6-0001
I0818 23:47:17.449741 8072 hierarchical.cpp:412] Deactivated framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.449863 8072 hierarchical.cpp:355] Removed framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.449934 8072 hierarchical.cpp:412] Deactivated framework
233c4092-ae37-4948-b072-16dc81f579c6-0001
I0818 23:47:17.450147 8072 hierarchical.cpp:355] Removed framework
233c4092-ae37-4948-b072-16dc81f579c6-0001
I0818 23:47:17.535396 8079 containerizer.cpp:2573] Container
1aa9123a-d94d-49db-9722-667a2101217c has exited
I0818 23:47:17.537827 8070 provisioner.cpp:490] Ignoring destroy request for
unknown container 1aa9123a-d94d-49db-9722-667a2101217c
I0818 23:47:17.538465 8071 slave.cpp:5329] Executor
'0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf' of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000 terminated with signal Killed
I0818 23:47:17.538542 8071 slave.cpp:5429] Cleaning up executor
'0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf' of framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.538772 8074 gc.cpp:59] Scheduling
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_37IbFd/slaves/233c4092-ae37-4948-b072-16dc81f579c6-S0/frameworks/233c4092-ae37-4948-b072-16dc81f579c6-0000/executors/0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf/runs/1aa9123a-d94d-49db-9722-667a2101217c'
for gc 6.99999376539259days in the future
I0818 23:47:17.538902 8071 slave.cpp:5525] Cleaning up framework
233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.538921 8074 gc.cpp:59] Scheduling
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_37IbFd/slaves/233c4092-ae37-4948-b072-16dc81f579c6-S0/frameworks/233c4092-ae37-4948-b072-16dc81f579c6-0000/executors/0a03978a-b2d7-4e74-89bc-7ef6f05a4eaf'
for gc 6.99999376355259days in the future
I0818 23:47:17.539119 8081 status_update_manager.cpp:285] Closing status
update streams for framework 233c4092-ae37-4948-b072-16dc81f579c6-0000
I0818 23:47:17.539227 8071 slave.cpp:843] Agent terminating
I0818 23:47:17.539336 8083 gc.cpp:59] Scheduling
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeRescindOnDestroy_1_37IbFd/slaves/233c4092-ae37-4948-b072-16dc81f579c6-S0/frameworks/233c4092-ae37-4948-b072-16dc81f579c6-0000'
for gc 6.99999376159704days in the future
I0818 23:47:17.539441 8073 master.cpp:1318] Agent
233c4092-ae37-4948-b072-16dc81f579c6-S0 at slave(779)@172.17.0.2:48361
(629d22a490b3) disconnected
I0818 23:47:17.539474 8073 master.cpp:3301] Disconnecting agent
233c4092-ae37-4948-b072-16dc81f579c6-S0 at slave(779)@172.17.0.2:48361
(629d22a490b3)
I0818 23:47:17.539551 8073 master.cpp:3320] Deactivating agent
233c4092-ae37-4948-b072-16dc81f579c6-S0 at slave(779)@172.17.0.2:48361
(629d22a490b3)
I0818 23:47:17.539721 8075 hierarchical.cpp:690] Agent
233c4092-ae37-4948-b072-16dc81f579c6-S0 deactivated
I0818 23:47:17.546499 2025 master.cpp:1160] Master terminating
I0818 23:47:17.547498 8077 hierarchical.cpp:626] Removed agent
233c4092-ae37-4948-b072-16dc81f579c6-S0
I0818 23:47:17.556628 2025 cluster.cpp:162] Creating default 'local' authorizer
I0818 23:47:17.559937 8084 master.cpp:442] Master
14553e2a-080f-4012-a840-666fa3c72468 (629d22a490b3) started on 172.17.0.2:48361
I0818 23:47:17.559955 8084 master.cpp:444] Flags at startup: --acls=""
--agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
--allocation_interval="1secs" --allocator="HierarchicalDRF"
--authenticate_agents="true" --authenticate_frameworks="true"
--authenticate_http_frameworks="true" --authenticate_http_readonly="true"
--authenticate_http_readwrite="true" --authenticators="crammd5"
--authorizers="local" --credentials="/tmp/pwzeGG/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"
--root_submissions="true" --user_sorter="drf" --version="false"
--webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/pwzeGG/master"
--zk_session_timeout="10secs"
I0818 23:47:17.560214 8084 master.cpp:494] Master only allowing authenticated
frameworks to register
I0818 23:47:17.560220 8084 master.cpp:508] Master only allowing authenticated
agents to register
I0818 23:47:17.560223 8084 master.cpp:521] Master only allowing authenticated
HTTP frameworks to register
I0818 23:47:17.560227 8084 credentials.hpp:37] Loading credentials for
authentication from '/tmp/pwzeGG/credentials'
I0818 23:47:17.560468 8084 master.cpp:566] Using default 'crammd5'
authenticator
I0818 23:47:17.560609 8084 http.cpp:1026] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readonly'
I0818 23:47:17.560770 8084 http.cpp:1026] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readwrite'
I0818 23:47:17.560909 8084 http.cpp:1026] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-scheduler'
I0818 23:47:17.561038 8084 master.cpp:646] Authorization enabled
I0818 23:47:17.561220 8070 hierarchical.cpp:171] Initialized hierarchical
allocator process
I0818 23:47:17.561326 8082 whitelist_watcher.cpp:77] No whitelist given
I0818 23:47:17.563791 8085 master.cpp:2163] Elected as the leading master!
I0818 23:47:17.563817 8085 master.cpp:1702] Recovering from registrar
I0818 23:47:17.563989 8071 registrar.cpp:347] Recovering registrar
I0818 23:47:17.564538 8071 registrar.cpp:391] Successfully fetched the
registry (0B) in 0ns
I0818 23:47:17.564621 8071 registrar.cpp:495] Applied 1 operations in 23644ns;
attempting to update the registry
I0818 23:47:17.565227 8071 registrar.cpp:552] Successfully updated the
registry in 0ns
I0818 23:47:17.565332 8071 registrar.cpp:424] Successfully recovered registrar
I0818 23:47:17.565697 8072 master.cpp:1801] Recovered 0 agents from the
registry (129B); allowing 10mins for agents to re-register
I0818 23:47:17.565752 8080 hierarchical.cpp:209] Skipping recovery of
hierarchical allocator: nothing to recover
I0818 23:47:17.570106 2025 process.cpp:3228] Attempting to spawn already
spawned process [email protected]:48361
I0818 23:47:17.571135 2025 containerizer.cpp:246] Using isolation:
posix/cpu,posix/mem,filesystem/posix,network/cni,environment_secret
W0818 23:47:17.571631 2025 backend.cpp:76] Failed to create 'aufs' backend:
AufsBackend requires root privileges
W0818 23:47:17.571750 2025 backend.cpp:76] Failed to create 'bind' backend:
BindBackend requires root privileges
I0818 23:47:17.571780 2025 provisioner.cpp:255] Using default backend 'copy'
I0818 23:47:17.573709 2025 cluster.cpp:448] Creating default 'local' authorizer
I0818 23:47:17.575634 8074 slave.cpp:250] Mesos agent started on
(780)@172.17.0.2:48361
I0818 23:47:17.575651 8074 slave.cpp:251] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_IDfAXf/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_SharedPersistentVolumeMultipleFrameworks_0_IDfAXf/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_SharedPersistentVolumeMultipleFrameworks_0_IDfAXf/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_SharedPersistentVolumeMultipleFrameworks_0_IDfAXf/executor_secret_key"
--executor_shutdown_grace_period="5secs"
--fetcher_cache_dir="/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_IDfAXf/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_SharedPersistentVolumeMultipleFrameworks_0_IDfAXf/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem" --launcher="posix"
--launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO"
--max_completed_executors_per_framework="150"
--oversubscribed_resources_interval="15secs" --perf_duration="10secs"
--perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns"
--quiet="false" --recover="reconnect" --recovery_timeout="15mins"
--registration_backoff_factor="10ms"
--resources="[{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":2048.0},"type":"SCALAR"},{"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":4096.0},"type":"SCALAR"}]"
--revocable_cpu_low_priority="true"
--runtime_dir="/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_IDfAXf"
--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_SharedPersistentVolumeMultipleFrameworks_0_7sYKb4"
I0818 23:47:17.576012 8074 credentials.hpp:86] Loading credential for
authentication from
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_IDfAXf/credential'
I0818 23:47:17.576025 2025 process.cpp:3228] Attempting to spawn already
spawned process [email protected]:48361
I0818 23:47:17.576129 8074 slave.cpp:283] Agent using credential for:
test-principal
I0818 23:47:17.576144 8074 credentials.hpp:37] Loading credentials for
authentication from
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_IDfAXf/http_credentials'
I0818 23:47:17.576406 8074 http.cpp:1026] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-executor'
I0818 23:47:17.576514 8074 http.cpp:1047] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-executor'
I0818 23:47:17.576719 8074 http.cpp:1026] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
I0818 23:47:17.576825 2025 sched.cpp:232] Version: 1.4.0
I0818 23:47:17.576841 8074 http.cpp:1047] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readonly'
I0818 23:47:17.577200 8074 http.cpp:1026] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readwrite'
I0818 23:47:17.577317 8074 http.cpp:1047] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readwrite'
I0818 23:47:17.577327 8085 sched.cpp:336] New master detected at
[email protected]:48361
I0818 23:47:17.577436 8085 sched.cpp:407] Authenticating with master
[email protected]:48361
I0818 23:47:17.577452 8085 sched.cpp:414] Using default CRAM-MD5 authenticatee
I0818 23:47:17.577618 8082 hierarchical.cpp:1925] No allocations performed
I0818 23:47:17.577716 8082 hierarchical.cpp:1468] Performed allocation for 0
agents in 129983ns
I0818 23:47:17.577730 8079 authenticatee.cpp:121] Creating new client SASL
connection
I0818 23:47:17.578052 8081 master.cpp:7837] Authenticating
[email protected]:48361
I0818 23:47:17.578210 8081 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1430)@172.17.0.2:48361
I0818 23:47:17.578469 8078 authenticator.cpp:98] Creating new server SASL
connection
I0818 23:47:17.578703 8072 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I0818 23:47:17.578728 8072 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0818 23:47:17.578829 8072 authenticator.cpp:204] Received SASL authentication
start
I0818 23:47:17.578886 8072 authenticator.cpp:326] Authentication requires more
steps
I0818 23:47:17.578977 8072 authenticatee.cpp:259] Received SASL authentication
step
I0818 23:47:17.579087 8072 authenticator.cpp:232] Received SASL authentication
step
I0818 23:47:17.579111 8072 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '629d22a490b3' server FQDN: '629d22a490b3'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I0818 23:47:17.579123 8072 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I0818 23:47:17.579154 8072 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0818 23:47:17.579180 8072 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '629d22a490b3' server FQDN: '629d22a490b3'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
I0818 23:47:17.579193 8072 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0818 23:47:17.579201 8072 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0818 23:47:17.579243 8072 authenticator.cpp:318] Authentication success
I0818 23:47:17.579371 8071 authenticatee.cpp:299] Authentication success
I0818 23:47:17.579483 8073 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1430)@172.17.0.2:48361
I0818 23:47:17.579500 8080 master.cpp:7867] Successfully authenticated
principal 'test-principal' at
[email protected]:48361
I0818 23:47:17.579716 8072 sched.cpp:513] Successfully authenticated with
master [email protected]:48361
I0818 23:47:17.579459 8074 slave.cpp:565] Agent resources:
[{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":2048.0},"type":"SCALAR"},{"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":4096.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I0818 23:47:17.579738 8072 sched.cpp:836] Sending SUBSCRIBE call to
[email protected]:48361
I0818 23:47:17.579747 8074 slave.cpp:573] Agent attributes: [ ]
I0818 23:47:17.579757 8074 slave.cpp:582] Agent hostname: 629d22a490b3
I0818 23:47:17.579866 8072 sched.cpp:869] Will retry registration in
955.24002ms if necessary
I0818 23:47:17.579951 8083 status_update_manager.cpp:177] Pausing sending
status updates
I0818 23:47:17.580085 8072 master.cpp:2894] Received SUBSCRIBE call for
framework 'default' at
[email protected]:48361
I0818 23:47:17.580163 8072 master.cpp:2228] Authorizing framework principal
'test-principal' to receive offers for roles '{ default-role }'
I0818 23:47:17.580585 8078 master.cpp:2974] Subscribing framework default with
checkpointing disabled and capabilities [ RESERVATION_REFINEMENT,
SHARED_RESOURCES ]
I0818 23:47:17.581132 8080 sched.cpp:759] Framework registered with
14553e2a-080f-4012-a840-666fa3c72468-0000
I0818 23:47:17.581177 8080 sched.cpp:773] Scheduler::registered took 23627ns
I0818 23:47:17.581315 8075 hierarchical.cpp:303] Added framework
14553e2a-080f-4012-a840-666fa3c72468-0000
I0818 23:47:17.581509 8075 hierarchical.cpp:1925] No allocations performed
I0818 23:47:17.581544 8075 hierarchical.cpp:2015] No inverse offers to send
out!
I0818 23:47:17.581580 8075 hierarchical.cpp:1468] Performed allocation for 0
agents in 110197ns
I0818 23:47:17.581646 8081 state.cpp:64] Recovering state from
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_7sYKb4/meta'
I0818 23:47:17.582026 8076 status_update_manager.cpp:203] Recovering status
update manager
I0818 23:47:17.582217 8084 containerizer.cpp:609] Recovering containerizer
I0818 23:47:17.583757 8083 provisioner.cpp:416] Provisioner recovery complete
I0818 23:47:17.584111 8085 slave.cpp:6210] Finished recovery
I0818 23:47:17.584519 8085 slave.cpp:6392] Querying resource estimator for
oversubscribable resources
I0818 23:47:17.584754 8085 status_update_manager.cpp:177] Pausing sending
status updates
I0818 23:47:17.584775 8082 slave.cpp:971] New master detected at
[email protected]:48361
I0818 23:47:17.584843 8082 slave.cpp:1006] Detecting new master
I0818 23:47:17.585000 8082 slave.cpp:6406] Received oversubscribable resources
{} from the resource estimator
I0818 23:47:17.585088 8082 slave.cpp:1033] Authenticating with master
[email protected]:48361
I0818 23:47:17.585146 8082 slave.cpp:1044] Using default CRAM-MD5 authenticatee
I0818 23:47:17.585377 8071 authenticatee.cpp:121] Creating new client SASL
connection
I0818 23:47:17.585603 8071 master.cpp:7837] Authenticating
slave(780)@172.17.0.2:48361
I0818 23:47:17.585731 8075 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1431)@172.17.0.2:48361
I0818 23:47:17.585955 8072 authenticator.cpp:98] Creating new server SASL
connection
I0818 23:47:17.586141 8072 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I0818 23:47:17.586159 8072 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0818 23:47:17.586230 8072 authenticator.cpp:204] Received SASL authentication
start
I0818 23:47:17.586263 8072 authenticator.cpp:326] Authentication requires more
steps
I0818 23:47:17.586335 8072 authenticatee.cpp:259] Received SASL authentication
step
I0818 23:47:17.586426 8078 authenticator.cpp:232] Received SASL authentication
step
I0818 23:47:17.586450 8078 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '629d22a490b3' server FQDN: '629d22a490b3'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I0818 23:47:17.586457 8078 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I0818 23:47:17.586477 8078 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0818 23:47:17.586488 8078 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '629d22a490b3' server FQDN: '629d22a490b3'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
I0818 23:47:17.586496 8078 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0818 23:47:17.586501 8078 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0818 23:47:17.586511 8078 authenticator.cpp:318] Authentication success
I0818 23:47:17.586621 8073 authenticatee.cpp:299] Authentication success
I0818 23:47:17.586663 8078 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1431)@172.17.0.2:48361
I0818 23:47:17.586704 8080 master.cpp:7867] Successfully authenticated
principal 'test-principal' at slave(780)@172.17.0.2:48361
I0818 23:47:17.586980 8077 slave.cpp:1128] Successfully authenticated with
master [email protected]:48361
I0818 23:47:17.587167 8077 slave.cpp:1572] Will retry registration in
8.860789ms if necessary
I0818 23:47:17.587323 8082 master.cpp:5712] Received register agent message
from slave(780)@172.17.0.2:48361 (629d22a490b3)
I0818 23:47:17.587437 8082 master.cpp:3803] Authorizing agent with principal
'test-principal'
I0818 23:47:17.587818 8081 master.cpp:5772] Authorized registration of agent
at slave(780)@172.17.0.2:48361 (629d22a490b3)
I0818 23:47:17.587899 8081 master.cpp:5865] Registering agent at
slave(780)@172.17.0.2:48361 (629d22a490b3) with id
14553e2a-080f-4012-a840-666fa3c72468-S0
I0818 23:47:17.588277 8075 registrar.cpp:495] Applied 1 operations in 54352ns;
attempting to update the registry
I0818 23:47:17.588901 8075 registrar.cpp:552] Successfully updated the
registry in 0ns
I0818 23:47:17.589128 8085 master.cpp:5912] Admitted agent
14553e2a-080f-4012-a840-666fa3c72468-S0 at slave(780)@172.17.0.2:48361
(629d22a490b3)
I0818 23:47:17.589660 8078 slave.cpp:4887] Received ping from
slave-observer(708)@172.17.0.2:48361
I0818 23:47:17.589845 8078 slave.cpp:1174] Registered with master
[email protected]:48361; given agent ID 14553e2a-080f-4012-a840-666fa3c72468-S0
I0818 23:47:17.589681 8085 master.cpp:5943] Registered agent
14553e2a-080f-4012-a840-666fa3c72468-S0 at slave(780)@172.17.0.2:48361
(629d22a490b3) with
[{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":2048.0},"type":"SCALAR"},{"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":4096.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I0818 23:47:17.590035 8077 status_update_manager.cpp:184] Resuming sending
status updates
I0818 23:47:17.590042 8080 hierarchical.cpp:593] Added agent
14553e2a-080f-4012-a840-666fa3c72468-S0 (629d22a490b3) with cpus:2; mem:2048;
disk(reservations: [(STATIC,default-role)]):4096; ports:[31000-32000]
(allocated: {})
I0818 23:47:17.590179 8078 slave.cpp:1194] Checkpointing SlaveInfo to
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_7sYKb4/meta/slaves/14553e2a-080f-4012-a840-666fa3c72468-S0/slave.info'
I0818 23:47:17.590459 8078 slave.cpp:1232] Forwarding total oversubscribed
resources {}
I0818 23:47:17.590612 8082 master.cpp:6688] Received update of agent
14553e2a-080f-4012-a840-666fa3c72468-S0 at slave(780)@172.17.0.2:48361
(629d22a490b3) with total oversubscribed resources {}
I0818 23:47:17.591034 8080 hierarchical.cpp:2015] No inverse offers to send
out!
I0818 23:47:17.591066 8080 hierarchical.cpp:1468] Performed allocation for 1
agents in 900506ns
I0818 23:47:17.591190 8080 hierarchical.cpp:660] Agent
14553e2a-080f-4012-a840-666fa3c72468-S0 (629d22a490b3) updated with total
resources cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)]):4096;
ports:[31000-32000]
I0818 23:47:17.591491 8071 master.cpp:7667] Sending 1 offers to framework
14553e2a-080f-4012-a840-666fa3c72468-0000 (default) at
[email protected]:48361
I0818 23:47:17.591871 8081 sched.cpp:933] Scheduler::resourceOffers took
68535ns
I0818 23:47:17.593458 8083 master.cpp:9164] Removing offer
14553e2a-080f-4012-a840-666fa3c72468-O0
I0818 23:47:17.593610 8083 master.cpp:4153] Processing ACCEPT call for offers:
[ 14553e2a-080f-4012-a840-666fa3c72468-O0 ] on agent
14553e2a-080f-4012-a840-666fa3c72468-S0 at slave(780)@172.17.0.2:48361
(629d22a490b3) for framework 14553e2a-080f-4012-a840-666fa3c72468-0000
(default) at [email protected]::
48361
I0818 23:47:17.593734 8083 master.cpp:3723] Authorizing principal
'test-principal' to create volumes
'[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"}]'
I0818 23:47:17.594142 8083 master.cpp:3530] Authorizing framework principal
'test-principal' to launch task a55e8c7b-5936-48d2-8662-f4e030880892
I0818 23:47:17.595365 8077 master.cpp:4576] Applying CREATE operation for
volumes
[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"}]
from framework 14553e2a-080f-4012-a840-666fa3c72468-0000 (default) at
[email protected]:48361 to agent
14553e2a-080f-4012-a840-666fa3c72468-S0 at slave(780)@172.17.0.2:48361
(629d22a490b3)
I0818 23:47:17.595749 8077 master.cpp:9110] Sending updated checkpointed
resources disk(reservations:
[(STATIC,default-role)])[id1:path1]<SHARED>:2048<1> to agent
14553e2a-080f-4012-a840-666fa3c72468-S0 at slave(780)@172.17.0.2:48361
(629d22a490b3)
I0818 23:47:17.596758 8080 slave.cpp:3449] Updated checkpointed resources from
{} to disk(reservations: [(STATIC,default-role)])[id1:path1]<SHARED>:2048<1>
I0818 23:47:17.597095 8077 master.cpp:9724] Adding task
a55e8c7b-5936-48d2-8662-f4e030880892 with resources
[{"allocation_info":{"role":"default-role"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"name":"mem","scalar":{"value":128.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"}]
on agent 14553e2a-080f-4012-a840-666fa3c72468-S0 at
slave(780)@172.17.0.2:48361 (629d22a490b3)
I0818 23:47:17.597566 8077 master.cpp:4816] Launching task
a55e8c7b-5936-48d2-8662-f4e030880892 of framework
14553e2a-080f-4012-a840-666fa3c72468-0000 (default) at
[email protected]:48361 with resources
[{"allocation_info":{"role":"default-role"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"name":"mem","scalar":{"value":128.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"}]
on agent 14553e2a-080f-4012-a840-666fa3c72468-S0 at
slave(780)@172.17.0.2:48361 (629d22a490b3)
I0818 23:47:17.598340 8071 slave.cpp:1701] Got assigned task
'a55e8c7b-5936-48d2-8662-f4e030880892' for framework
14553e2a-080f-4012-a840-666fa3c72468-0000
I0818 23:47:17.598917 8071 slave.cpp:1982] Authorizing task
'a55e8c7b-5936-48d2-8662-f4e030880892' for framework
14553e2a-080f-4012-a840-666fa3c72468-0000
I0818 23:47:17.598959 8071 slave.cpp:6709] Authorizing framework principal
'test-principal' to launch task a55e8c7b-5936-48d2-8662-f4e030880892
I0818 23:47:17.599735 8084 slave.cpp:2169] Launching task
'a55e8c7b-5936-48d2-8662-f4e030880892' for framework
14553e2a-080f-4012-a840-666fa3c72468-0000
I0818 23:47:17.600343 8084 paths.cpp:578] Trying to chown
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_7sYKb4/slaves/14553e2a-080f-4012-a840-666fa3c72468-S0/frameworks/14553e2a-080f-4012-a840-666fa3c72468-0000/executors/a55e8c7b-5936-48d2-8662-f4e030880892/runs/8f55f827-bef7-448c-8149-a25d0554db8c'
to user 'mesos'
I0818 23:47:17.600567 8084 slave.cpp:7165] Launching executor
'a55e8c7b-5936-48d2-8662-f4e030880892' of framework
14553e2a-080f-4012-a840-666fa3c72468-0000 with resources
[{"allocation_info":{"role":"default-role"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"}]
in work directory
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_7sYKb4/slaves/14553e2a-080f-4012-a840-666fa3c72468-S0/frameworks/14553e2a-080f-4012-a840-666fa3c72468-0000/executors/a55e8c7b-5936-48d2-8662-f4e030880892/runs/8f55f827-bef7-448c-8149-a25d0554db8c'
I0818 23:47:17.600863 8081 hierarchical.cpp:887] Updated allocation of
framework 14553e2a-080f-4012-a840-666fa3c72468-0000 on agent
14553e2a-080f-4012-a840-666fa3c72468-S0 from cpus(allocated: default-role):2;
mem(allocated: default-role):2048; disk(allocated: default-role)(reservations:
[(STATIC,default-role)]):4096; ports(allocated: default-role):[31000-32000] to
cpus(allocated: default-role):2; mem(allocated: default-role):2048;
disk(allocated: default-role)(reservations: [(STATIC,default-role)]):2048;
ports(allocated: default-role):[31000-32000]; disk(allocated:
default-role)(reservations: [(STATIC,default-role)])[id1:path1]<SHARED>:2048<1>
I0818 23:47:17.601372 8084 slave.cpp:2398] Queued task
'a55e8c7b-5936-48d2-8662-f4e030880892' for executor
'a55e8c7b-5936-48d2-8662-f4e030880892' of framework
14553e2a-080f-4012-a840-666fa3c72468-0000
I0818 23:47:17.601450 8084 slave.cpp:924] Successfully attached file
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_7sYKb4/slaves/14553e2a-080f-4012-a840-666fa3c72468-S0/frameworks/14553e2a-080f-4012-a840-666fa3c72468-0000/executors/a55e8c7b-5936-48d2-8662-f4e030880892/runs/8f55f827-bef7-448c-8149-a25d0554db8c'
I0818 23:47:17.601483 8084 slave.cpp:924] Successfully attached file
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_7sYKb4/slaves/14553e2a-080f-4012-a840-666fa3c72468-S0/frameworks/14553e2a-080f-4012-a840-666fa3c72468-0000/executors/a55e8c7b-5936-48d2-8662-f4e030880892/runs/8f55f827-bef7-448c-8149-a25d0554db8c'
I0818 23:47:17.601675 8081 hierarchical.cpp:1152] Recovered cpus(allocated:
default-role):1; mem(allocated: default-role):1920; disk(allocated:
default-role)(reservations: [(STATIC,default-role)]):2048; ports(allocated:
default-role):[31000-32000] (total: cpus:2; mem:2048; disk(reservations:
[(STATIC,default-role)]):2048; ports:[31000-32000]; disk(reservations:
[(STATIC,default-role)])[id1:path1]<SHARED>:2048<1>, allocated: cpus(allocated:
default-role):1; mem(allocated: default-role):128; disk(allocated: default:
-role)(reservations: [(STATIC,default-role)])[id1:path1]<SHARED>:2048<1>) on
agent 14553e2a-080f-4012-a840-666fa3c72468-S0 from framework
14553e2a-080f-4012-a840-666fa3c72468-0000
I0818 23:47:17.601764 8084 slave.cpp:2856] Launching container
8f55f827-bef7-448c-8149-a25d0554db8c for executor
'a55e8c7b-5936-48d2-8662-f4e030880892' of framework
14553e2a-080f-4012-a840-666fa3c72468-0000
I0818 23:47:17.602080 8085 containerizer.cpp:1083] Starting container
8f55f827-bef7-448c-8149-a25d0554db8c
I0818 23:47:17.602475 8085 containerizer.cpp:2673] Transitioning the state of
container 8f55f827-bef7-448c-8149-a25d0554db8c from PROVISIONING to PREPARING
I0818 23:47:17.603122 8074 posix.cpp:204] Changing the ownership of the
persistent volume at
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_7sYKb4/volumes/roles/default-role/id1'
with uid 1000 and gid 1000
I0818 23:47:17.603189 8074 posix.cpp:250] Adding symlink from
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_7sYKb4/volumes/roles/default-role/id1'
to
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_7sYKb4/slaves/14553e2a-080f-4012-a840-666fa3c72468-S0/frameworks/14553e2a-080f-4012-a840-666fa3c72468-0000/executors/a55e8c7b-5936-48d2-8662-f4e030880892/runs/8f55f827-bef7-448c-8149-a25d0554db8c/path1'
for persistent volume disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[id1:path1]<SHARED>:2048 of container
8f55f827-bef7-448c-8149-a25d0554db8c
I0818 23:47:17.606670 8071 containerizer.cpp:1657] Launching
'mesos-containerizer' with flags '--help="false"
--launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=\/mesos\/build\/src"],"shell":false,"value":"\/mesos\/build\/src\/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.2:48361"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_7sYKb4\/slaves\/14553e2a-080f-4012-a840-666fa3c72468-S0\/frameworks\/14553e2a-080f-4012-a840-666fa3c72468-0000\/executors\/a55e8c7b-5936-48d2-8662-f4e030880892\/runs\/8f55f827-bef7-448c-8149-a25d0554db8c"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiI4ZjU1ZjgyNy1iZWY3LTQ0OGMtODE0OS1hMjVkMDU1NGRiOGMiLCJlaWQiOiJhNTVlOGM3Yi01OTM2LTQ4ZDItODY2Mi1mNGUwMzA4ODA4OTIiLCJmaWQiOiIxNDU1M2UyYS0wODBmLTQwMTItYTg0MC02NjZmYTNjNzI0NjgtMDAwMCJ9.8IlCX_FCHP_JpZG93kY200BHmv7B1IU6ssgRJBPesoc"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"a55e8c7b-5936-48d2-8662-f4e030880892"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"14553e2a-080f-4012-a840-666fa3c72468-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"14553e2a-080f-4012-a840-666fa3c72468-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(780)@172.17.0.2:48361"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_7sYKb4\/slaves\/14553e2a-080f-4012-a840-666fa3c72468-S0\/frameworks\/14553e2a-080f-4012-a840-666fa3c72468-0000\/executors\/a55e8c7b-5936-48d2-8662-f4e030880892\/runs\/8f55f827-bef7-448c-8149-a25d0554db8c"}]},"task_environment":{},"user":"mesos","working_directory":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_7sYKb4\/slaves\/14553e2a-080f-4012-a840-666fa3c72468-S0\/frameworks\/14553e2a-080f-4012-a840-666fa3c72468-0000\/executors\/a55e8c7b-5936-48d2-8662-f4e030880892\/runs\/8f55f827-bef7-448c-8149-a25d0554db8c"}"
--pipe_read="10" --pipe_write="13"
--runtime_directory="/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_IDfAXf/containers/8f55f827-bef7-448c-8149-a25d0554db8c"
--unshare_namespace_mnt="false"'
I0818 23:47:17.609231 8071 launcher.cpp:140] Forked child with pid '8249' for
container '8f55f827-bef7-448c-8149-a25d0554db8c'
I0818 23:47:17.609777 8071 containerizer.cpp:2673] Transitioning the state of
container 8f55f827-bef7-448c-8149-a25d0554db8c from PREPARING to ISOLATING
I0818 23:47:17.612256 8070 containerizer.cpp:2673] Transitioning the state of
container 8f55f827-bef7-448c-8149-a25d0554db8c from ISOLATING to FETCHING
I0818 23:47:17.612404 8073 fetcher.cpp:379] Starting to fetch URIs for
container: 8f55f827-bef7-448c-8149-a25d0554db8c, directory:
/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_7sYKb4/slaves/14553e2a-080f-4012-a840-666fa3c72468-S0/frameworks/14553e2a-080f-4012-a840-666fa3c72468-0000/executors/a55e8c7b-5936-48d2-8662-f4e030880892/runs/8f55f827-bef7-448c-8149-a25d0554db8c
I0818 23:47:17.613210 8076 containerizer.cpp:2673] Transitioning the state of
container 8f55f827-bef7-448c-8149-a25d0554db8c from FETCHING to RUNNING
I0818 23:47:17.782330 8250 exec.cpp:162] Version: 1.4.0
I0818 23:47:17.787248 8078 slave.cpp:3881] Got registration for executor
'a55e8c7b-5936-48d2-8662-f4e030880892' of framework
14553e2a-080f-4012-a840-666fa3c72468-0000 from executor(1)@172.17.0.2:48703
I0818 23:47:17.789764 8076 slave.cpp:2603] Sending queued task
'a55e8c7b-5936-48d2-8662-f4e030880892' to executor
'a55e8c7b-5936-48d2-8662-f4e030880892' of framework
14553e2a-080f-4012-a840-666fa3c72468-0000 at executor(1)@172.17.0.2:48703
I0818 23:47:17.791574 8261 exec.cpp:237] Executor registered on agent
14553e2a-080f-4012-a840-666fa3c72468-S0
I0818 23:47:17.794991 8264 executor.cpp:171] Received SUBSCRIBED event
I0818 23:47:17.795361 8264 executor.cpp:175] Subscribed executor on
629d22a490b3
I0818 23:47:17.795646 8264 executor.cpp:171] Received LAUNCH event
I0818 23:47:17.795897 8264 executor.cpp:633] Starting task
a55e8c7b-5936-48d2-8662-f4e030880892
I0818 23:47:17.801815 8264 executor.cpp:477] Running
'/mesos/build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>'
I0818 23:47:17.804733 8264 executor.cpp:646] Forked command at 8268
I0818 23:47:17.808389 8081 slave.cpp:4345] Handling status update TASK_RUNNING
(UUID: d19c0db9-dd97-4436-b3a1-e42ec2140c53) for task
a55e8c7b-5936-48d2-8662-f4e030880892 of:
framework 14553e2a-080f-4012-a840-666fa3c72468-0000 from
executor(1)@172.17.0.2:48703
I0818 23:47:17.810137 8070 status_update_manager.cpp:323] Received status
update TASK_RUNNING (UUID: d19c0db9-dd97-4436-b3a1-e42ec2140c53) for task
a55e8c7b-5936-48d2-8662-f4e030880892 of framework
14553e2a-080f-4012-a840-666fa3c72468-0000
I0818 23:47:17.810178 8070 status_update_manager.cpp:500] Creating
StatusUpdate stream for task a55e8c7b-5936-48d2-8662-f4e030880892 of framework
14553e2a-080f-4012-a840-666fa3c72468-0000
I0818 23:47:17.810719 8070 status_update_manager.cpp:377] Forwarding update
TASK_RUNNING (UUID: d19c0db9-dd97-4436-b3a1-e42ec2140c53) for task
a55e8c7b-5936-48d2-8662-f4e030880892 of framework
14553e2a-080f-4012-a840-666fa3c72468-0000 to the agent
I0818 23:47:17.810977 8085 slave.cpp:4797] Forwarding the update TASK_RUNNING
(UUID: d19c0db9-dd97-4436-b3a1-e42ec2140c53) for task
a55e8c7b-5936-48d2-8662-f4e030880892 of framework
14553e2a-080f-4012-a840-666fa3c72468-0000 to [email protected]:48361
I0818 23:47:17.811151 8085 slave.cpp:4691] Status update manager successfully
handled status update TASK_RUNNING (UUID: d19c0db9-dd97-4436-b3a1-e42ec2140c53)
for task a55e8c7b-5936-48d2-8662-f4e030880892 of framework
14553e2a-080f-4012-a840-666fa3c72468-0000
I0818 23:47:17.811188 8085 slave.cpp:4707] Sending acknowledgement for status
update TASK_RUNNING (UUID: d19c0db9-dd97-4436-b3a1-e42ec2140c53) for task
a55e8c7b-5936-48d2-8662-f4e030880892 of framework
14553e2a-080f-4012-a840-666fa3c72468-0000 to executor(1)@172.17.0.2:48703
I0818 23:47:17.811449 8081 master.cpp:6846] Status update TASK_RUNNING (UUID:
d19c0db9-dd97-4436-b3a1-e42ec2140c53) for task
a55e8c7b-5936-48d2-8662-f4e030880892 of framework
14553e2a-080f-4012-a840-666fa3c72468-0000 from agent
14553e2a-080f-4012-a840-666fa3c72468-S0 at slave(780)@172.17.0.2:48361
(629d22a490b3)
I0818 23:47:17.811517 8081 master.cpp:6908] Forwarding status update
TASK_RUNNING (UUID: d19c0db9-dd97-4436-b3a1-e42ec2140c53) for task
a55e8c7b-5936-48d2-8662-f4e030880892 of framework
14553e2a-080f-4012-a840-666fa3c72468-0000
I0818 23:47:17.811753 8081 master.cpp:8933] Updating the state of task
a55e8c7b-5936-48d2-8662-f4e030880892 of framework
14553e2a-080f-4012-a840-666fa3c72468-0000 (latest state: TASK_RUNNING, status
update state: TASK_RUNNING)
I0818 23:47:17.811982 8078 sched.cpp:1041] Scheduler::statusUpdate took 91462ns
I0818 23:47:17.812297 8080 master.cpp:5477] Processing ACKNOWLEDGE call
d19c0db9-dd97-4436-b3a1-e42ec2140c53 for task
a55e8c7b-5936-48d2-8662-f4e030880892 of framework
14553e2a-080f-4012-a840-666fa3c72468-0000 (default) at
[email protected]:48361 on agent
14553e2a-080f-4012-a840-666fa3c72468-S0
I0818 23:47:17.812633 8079 status_update_manager.cpp:395] Received status
update acknowledgement (UUID: d19c0db9-dd97-4436-b3a1-e42ec2140c53) for task
a55e8c7b-5936-48d2-8662-f4e030880892 of framework
14553e2a-080f-4012-a840-666fa3c72468-0000
I0818 23:47:17.812922 8079 slave.cpp:3609] Status update manager successfully
handled status update acknowledgement (UUID:
d19c0db9-dd97-4436-b3a1-e42ec2140c53) for task
a55e8c7b-5936-48d2-8662-f4e030880892 of framework
14553e2a-080f-4012-a840-666fa3c72468-0000
I0818 23:47:17.817744 8084 process.cpp:3933] Handling HTTP event for process
'metrics' with path: '/metrics/snapshot'
I0818 23:47:17.818581 8084 http.cpp:832] Authorizing principal 'ANY' to GET
the endpoint '/metrics/snapshot'
I0818 23:47:17.838655 2025 process.cpp:3228] Attempting to spawn already
spawned process [email protected]:48361
I0818 23:47:17.839516 2025 sched.cpp:232] Version: 1.4.0
I0818 23:47:17.840126 8077 sched.cpp:336] New master detected at
[email protected]:48361
I0818 23:47:17.840207 8077 sched.cpp:407] Authenticating with master
[email protected]:48361
I0818 23:47:17.840222 8077 sched.cpp:414] Using default CRAM-MD5 authenticatee
I0818 23:47:17.840459 8085 authenticatee.cpp:121] Creating new client SASL
connection
I0818 23:47:17.840791 8081 master.cpp:7837] Authenticating
[email protected]:48361
I0818 23:47:17.840929 8084 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1432)@172.17.0.2:48361
I0818 23:47:17.841298 8079 authenticator.cpp:98] Creating new server SASL
connection
I0818 23:47:17.841578 8079 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I0818 23:47:17.841601 8079 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0818 23:47:17.841742 8074 authenticator.cpp:204] Received SASL authentication
start
I0818 23:47:17.841822 8074 authenticator.cpp:326] Authentication requires more
steps
I0818 23:47:17.841958 8074 authenticatee.cpp:259] Received SASL authentication
step
I0818 23:47:17.842059 8074 authenticator.cpp:232] Received SASL authentication
step
I0818 23:47:17.842083 8074 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '629d22a490b3' server FQDN: '629d22a490b3'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I0818 23:47:17.842100 8074 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I0818 23:47:17.842146 8074 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0818 23:47:17.842165 8074 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '629d22a490b3' server FQDN: '629d22a490b3'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
I0818 23:47:17.842178 8074 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0818 23:47:17.842186 8074 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0818 23:47:17.842200 8074 authenticator.cpp:318] Authentication success
I0818 23:47:17.842315 8083 authenticatee.cpp:299] Authentication success
I0818 23:47:17.842430 8072 master.cpp:7867] Successfully authenticated
principal 'test-principal' at
[email protected]:48361
I0818 23:47:17.842439 8074 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1432)@172.17.0.2:48361
I0818 23:47:17.842631 8080 sched.cpp:513] Successfully authenticated with
master [email protected]:48361
I0818 23:47:17.842648 8080 sched.cpp:836] Sending SUBSCRIBE call to
[email protected]:48361
I0818 23:47:17.842752 8080 sched.cpp:869] Will retry registration in
1.088873001secs if necessary
I0818 23:47:17.842957 8077 master.cpp:2894] Received SUBSCRIBE call for
framework 'default' at
[email protected]:48361
I0818 23:47:17.843029 8077 master.cpp:2228] Authorizing framework principal
'test-principal' to receive offers for roles '{ default-role }'
I0818 23:47:17.843394 8081 master.cpp:2974] Subscribing framework default with
checkpointing disabled and capabilities [ RESERVATION_REFINEMENT,
SHARED_RESOURCES ]
I0818 23:47:17.843912 8084 hierarchical.cpp:303] Added framework
14553e2a-080f-4012-a840-666fa3c72468-0001
I0818 23:47:17.843912 8081 sched.cpp:759] Framework registered with
14553e2a-080f-4012-a840-666fa3c72468-0001
I0818 23:47:17.843972 8081 sched.cpp:773] Scheduler::registered took 26056ns
I0818 23:47:17.845564 8084 hierarchical.cpp:2015] No inverse offers to send
out!
I0818 23:47:17.845608 8084 hierarchical.cpp:1468] Performed allocation for 1
agents in 1.535396ms
I0818 23:47:17.846292 8073 master.cpp:7667] Sending 1 offers to framework
14553e2a-080f-4012-a840-666fa3c72468-0001 (default) at
[email protected]:48361
I0818 23:47:17.846753 8073 sched.cpp:933] Scheduler::resourceOffers took
83201ns
I0818 23:47:17.848698 8083 master.cpp:9164] Removing offer
14553e2a-080f-4012-a840-666fa3c72468-O1
I0818 23:47:17.848836 8083 master.cpp:4153] Processing ACCEPT call for offers:
[ 14553e2a-080f-4012-a840-666fa3c72468-O1 ] on agent
14553e2a-080f-4012-a840-666fa3c72468-S0 at slave(780)@172.17.0.2:48361
(629d22a490b3) for framework 14553e2a-080f-4012-a840-666fa3c72468-0001
(default) at [email protected]:48361
I0818 23:47:17.848922 8083 master.cpp:3530] Authorizing framework principal
'test-principal' to launch task 6d750614-1a20-4b99-a79d-1a050ad35395
I0818 23:47:17.850955 8075 master.cpp:9724] Adding task
6d750614-1a20-4b99-a79d-1a050ad35395 with resources
[{"allocation_info":{"role":"default-role"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"name":"mem","scalar":{"value":256.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"path1","mod[
OK ]
DiskResource/PersistentVolumeTest.SharedPersistentVolumeRescindOnDestroy/1 (211
ms)
[ RUN ]
DiskResource/PersistentVolumeTest.SharedPersistentVolumeMultipleFrameworks/0
[ OK ]
DiskResource/PersistentVolumeTest.SharedPersistentVolumeMultipleFrameworks/0
(760 ms)
[ RUN ]
DiskResource/PersistentVolumeTest.SharedPersistentVolumeMultipleFrameworks/1
[ OK ]
DiskResource/PersistentVolumeTest.SharedPersistentVolumeMultipleFrameworks/1
(750 ms)
[ RUN ]
DiskResource/PersistentVolumeTest.SharedPersistentVolumeMasterFailover/0
[ OK ]
DiskResource/PersistentVolumeTest.SharedPersistentVolumeMasterFailover/0 (508
ms)
[ RUN ]
DiskResource/PersistentVolumeTest.SharedPersistentVolumeMasterFailover/1
[ OK ]
DiskResource/PersistentVolumeTest.SharedPersistentVolumeMasterFailover/1 (507
ms)
[ RUN ]
DiskResource/PersistentVolumeTest.DestroyPersistentVolumeMultipleTasks/0
[ OK ]
DiskResource/PersistentVolumeTest.DestroyPersistentVolumeMultipleTasks/0 (812
ms)
[ RUN ]
DiskResource/PersistentVolumeTest.DestroyPersistentVolumeMultipleTasks/1
[ OK ]
DiskResource/PersistentVolumeTest.DestroyPersistentVolumeMultipleTasks/1 (781
ms)
[ RUN ]
DiskResource/PersistentVolumeTest.SharedPersistentVolumeMultipleIterations/0
[ OK ]
DiskResource/PersistentVolumeTest.SharedPersistentVolumeMultipleIterations/0
(221 ms)
[ RUN ]
DiskResource/PersistentVolumeTest.SharedPersistentVolumeMultipleIterations/1
[ OK ]
DiskResource/PersistentVolumeTest.SharedPersistentVolumeMultipleIterations/1
(322 ms)
[ RUN ] DiskResource/PersistentVolumeTest.SlaveRecovery/0
[ OK ] DiskResource/PersistentVolumeTest.SlaveRecovery/0 (433 ms)
[ RUN ] DiskResource/PersistentVolumeTest.SlaveRecovery/1
[ OK ] DiskResource/PersistentVolumeTest.SlaveRecovery/1 (414 ms)
[ RUN ] DiskResource/PersistentVolumeTest.GoodACLCreateThenDestroy/0
[ OK ] DiskResource/PersistentVolumeTest.GoodACLCreateThenDestroy/0 (79
ms)
[ RUN ] DiskResource/PersistentVolumeTest.GoodACLCreateThenDestroy/1
[ OK ] DiskResource/PersistentVolumeTest.GoodACLCreateThenDestroy/1 (73
ms)
[ RUN ] DiskResource/PersistentVolumeTest.GoodACLNoPrincipal/0
[ OK ] DiskResource/PersistentVolumeTest.GoodACLNoPrincipal/0 (71 ms)
[ RUN ] DiskResource/PersistentVolumeTest.GoodACLNoPrincipal/1
[ OK ] DiskResource/PersistentVolumeTest.GoodACLNoPrincipal/1 (84 ms)
[ RUN ] DiskResource/PersistentVolumeTest.BadACLNoPrincipal/0
[ OK ] DiskResource/PersistentVolumeTest.BadACLNoPrincipal/0 (78 ms)
[ RUN ] DiskResource/PersistentVolumeTest.BadACLNoPrincipal/1
[ OK ] DiskResource/PersistentVolumeTest.BadACLNoPrincipal/1 (87 ms)
[ RUN ] DiskResource/PersistentVolumeTest.BadACLDropCreateAndDestroy/0
[ OK ] DiskResource/PersistentVolumeTest.BadACLDropCreateAndDestroy/0 (79
ms)
[ RUN ] DiskResource/PersistentVolumeTest.BadACLDropCreateAndDestroy/1
[ OK ] DiskResource/PersistentVolumeTest.BadACLDropCreateAndDestroy/1 (83
ms)
[----------] 34 tests from DiskResource/PersistentVolumeTest (9799 ms total)
[----------] 9 tests from Endpoint/SlaveEndpointTest
[ RUN ] Endpoint/SlaveEndpointTest.AuthorizedRequest/0
[ OK ] Endpoint/SlaveEndpointTest.AuthorizedRequest/0 (32 ms)
[ RUN ] Endpoint/SlaveEndpointTest.AuthorizedRequest/1
[ OK ] Endpoint/SlaveEndpointTest.AuthorizedRequest/1 (33 ms)
[ RUN ] Endpoint/SlaveEndpointTest.AuthorizedRequest/2
[ OK ] Endpoint/SlaveEndpointTest.AuthorizedRequest/2 (33 ms)
[ RUN ] Endpoint/SlaveEndpointTest.UnauthorizedRequest/0
[ OK ] Endpoint/SlaveEndpointTest.UnauthorizedRequest/0 (33 ms)
[ RUN ] Endpoint/SlaveEndpointTest.UnauthorizedRequest/1
[ OK ] Endpoint/SlaveEndpointTest.UnauthorizedRequest/1 (33 ms)
[ RUN ] Endpoint/SlaveEndpointTest.UnauthorizedRequest/2
[ OK ] Endpoint/SlaveEndpointTest.UnauthorizedRequest/2 (35 ms)
[ RUN ] Endpoint/SlaveEndpointTest.NoAuthorizer/0
[ OK ] Endpoint/SlaveEndpointTest.NoAuthorizer/0 (32 ms)
[ RUN ] Endpoint/SlaveEndpointTest.NoAuthorizer/1
[ OK ] Endpoint/SlaveEndpointTest.NoAuthorizer/1 (36 ms)
[ RUN ] Endpoint/SlaveEndpointTest.NoAuthorizer/2
[ OK ] Endpoint/SlaveEndpointTest.NoAuthorizer/2 (34 ms)
[----------] 9 tests from Endpoint/SlaveEndpointTest (316 ms total)
[----------] Global test environment tear-down
[==========] 1616 tests from 177 test cases ran. (422399 ms total)
[ PASSED ] 1615 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] MasterTest.LaunchCombinedOfferTest
1 FAILED TEST
YOU HAVE 20 DISABLED TESTS
make[3]: Leaving directory `/mesos/build'
make[2]: Leaving directory `/mesos/build'
make[1]: Leaving directory `/mesos/build'
e":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"}]
on agent 14553e2a-080f-4012-a840-666fa3c72468-S0 at
slave(780)@172.17.0.2:48361 (629d22a490b3)
I0818 23:47:17.851506 8075 master.cpp:4816] Launching task
6d750614-1a20-4b99-a79d-1a050ad35395 of framework
14553e2a-080f-4012-a840-666fa3c72468-0001 (default) at
[email protected]:48361 with resources
[{"allocation_info":{"role":"default-role"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"name":"mem","scalar":{"value":256.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"}]
on agent 14553e2a-080f-4012-a840-666fa3c72468-S0 at
slave(780)@172.17.0.2:48361 (629d22a490b3)
I0818 23:47:17.852489 8080 slave.cpp:1701] Got assigned task
'6d750614-1a20-4b99-a79d-1a050ad35395' for framework
14553e2a-080f-4012-a840-666fa3c72468-0001
I0818 23:47:17.853349 8080 slave.cpp:1982] Authorizing task
'6d750614-1a20-4b99-a79d-1a050ad35395' for framework
14553e2a-080f-4012-a840-666fa3c72468-0001
I0818 23:47:17.853404 8080 slave.cpp:6709] Authorizing framework principal
'test-principal' to launch task 6d750614-1a20-4b99-a79d-1a050ad35395
I0818 23:47:17.854647 8084 slave.cpp:2169] Launching task
'6d750614-1a20-4b99-a79d-1a050ad35395' for framework
14553e2a-080f-4012-a840-666fa3c72468-0001
I0818 23:47:17.854667 8077 hierarchical.cpp:887] Updated allocation of
framework 14553e2a-080f-4012-a840-666fa3c72468-0001 on agent
14553e2a-080f-4012-a840-666fa3c72468-S0 from cpus(allocated: default-role):1;
mem(allocated: default-role):1920; disk(allocated: default-role)(reservations:
[(STATIC,default-role)]):2048; ports(allocated: default-role):[31000-32000];
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[id1:path1]<SHARED>:2048<1> to cpus(allocated:
default-role):1; mem(allocated: default-role):1920; disk(allocated:
default-role)(reservations: [(STATIC,default-role)]):2048; ports(allocated:
default-role):[31000-32000]; disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[id1:path1]<SHARED>:2048<1>
I0818 23:47:17.855296 8084 paths.cpp:578] Trying to chown
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_7sYKb4/slaves/14553e2a-080f-4012-a840-666fa3c72468-S0/frameworks/14553e2a-080f-4012-a840-666fa3c72468-0001/executors/6d750614-1a20-4b99-a79d-1a050ad35395/runs/565d6c7f-458f-4792-9c55-0450495f0313'
to user 'mesos'
I0818 23:47:17.855424 8077 hierarchical.cpp:1152] Recovered ports(allocated:
default-role):[31000-32000]; mem(allocated: default-role):1664; disk(allocated:
default-role)(reservations: [(STATIC,default-role)]):2048 (total: cpus:2;
mem:2048; disk(reservations: [(STATIC,default-role)]):2048;
ports:[31000-32000]; disk(reservations:
[(STATIC,default-role)])[id1:path1]<SHARED>:2048<1>, allocated: cpus(allocated:
default-role):2; mem(allocated: default-role):384; disk(allocated:
default-role)(reservations:
[(STATIC,default-role)])[id1:path1]<SHARED>:2048<2>) on agent
14553e2a-080f-4012-a840-666fa3c72468-S0 from framework
14553e2a-080f-4012-a840-666fa3c72468-0001
I0818 23:47:17.855550 8084 slave.cpp:7165] Launching executor
'6d750614-1a20-4b99-a79d-1a050ad35395' of framework
14553e2a-080f-4012-a840-666fa3c72468-0001 with resources
[{"allocation_info":{"role":"default-role"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"}]
in work directory
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_7sYKb4/slaves/14553e2a-080f-4012-a840-666fa3c72468-S0/frameworks/14553e2a-080f-4012-a840-666fa3c72468-0001/executors/6d750614-1a20-4b99-a79d-1a050ad35395/runs/565d6c7f-458f-4792-9c55-0450495f0313'
I0818 23:47:17.856465 8084 slave.cpp:2398] Queued task
'6d750614-1a20-4b99-a79d-1a050ad35395' for executor
'6d750614-1a20-4b99-a79d-1a050ad35395' of framework
14553e2a-080f-4012-a840-666fa3c72468-0001
I0818 23:47:17.856545 8084 slave.cpp:924] Successfully attached file
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_7sYKb4/slaves/14553e2a-080f-4012-a840-666fa3c72468-S0/frameworks/14553e2a-080f-4012-a840-666fa3c72468-0001/executors/6d750614-1a20-4b99-a79d-1a050ad35395/runs/565d6c7f-458f-4792-9c55-0450495f0313'
I0818 23:47:17.856580 8084 slave.cpp:924] Successfully attached file
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleFrameworks_0_7sYKb4/slaves/14553e2a-080f-4012-a840-666fa3c72468-S0/frameworks/14553e2a-080f-4012-a840-666fa3c72468-0001/executors/6d750614-1a20-4b99-a79d-1a050ad35395/runs/565d6c7f-458f-4792-9c55-0450495f0313'
I0818 23:47:17.856874 8084 slave.cpp:2856] Launching container
565d6c7f-458f-4792-9c55-0450495f0313 for executor
'6d750614-1a20-4b99-a79d-1a050ad35395' of framework
14553e2a-080f-4012-a840-666fa3c72468-0001
I0818 23:47:17.857218 8070 containerizer.cpp:1083] Starting container
565d6c7f-458f-4792-9c55-0450495f0313
I0818 23:47:17.857626 8070 containerizer.cpp:2673] Transitioning the state of
container 565d6c7f-458f-4792-9c55-0450495f0313 from PROVISIONING to PREPARING
{code}
> ASF CI has interleaved logging.
> -------------------------------
>
> Key: MESOS-6356
> URL: https://issues.apache.org/jira/browse/MESOS-6356
> Project: Mesos
> Issue Type: Bug
> Reporter: Anand Mazumdar
> Labels: flaky, flaky-test, mesosphere, test
> Attachments: consoleText.zip
>
>
> It seems that the build output for test runs from ASF CI has interleaved
> logging making it very hard to debug test failures. This looks to have
> started happening after the unified unified cgroups isolator patches went in
> but we are yet to find a correlation.
> An example ASF CI run with interleaved logs:
> https://builds.apache.org/job/Mesos/BUILDTOOL=autotools,COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)&&(!ubuntu-6)/2762/changes
> (Also attached this to the ticket)
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
