See <https://builds.apache.org/job/Mesos-Reviewbot/21561/display/redirect>
------------------------------------------
[...truncated 33.47 MB...]
I0207 15:16:31.233033 6423 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '41fc79203ff5' server FQDN: '41fc79203ff5'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
I0207 15:16:31.233057 6423 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0207 15:16:31.233070 6423 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0207 15:16:31.233098 6423 authenticator.cpp:318] Authentication success
I0207 15:16:31.233280 6424 master.cpp:9008] Successfully authenticated
principal 'test-principal' at
scheduler-45fd4720-32c6-484c-9453-8b394ef5f431@172.17.0.5:45258
I0207 15:16:31.233332 6428 authenticatee.cpp:299] Authentication success
I0207 15:16:31.233373 6425 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1604)@172.17.0.5:45258
I0207 15:16:31.233609 6431 sched.cpp:502] Successfully authenticated with
master master@172.17.0.5:45258
I0207 15:16:31.233634 6431 sched.cpp:824] Sending SUBSCRIBE call to
master@172.17.0.5:45258
I0207 15:16:31.233767 6431 sched.cpp:857] Will retry registration in
977.653455ms if necessary
I0207 15:16:31.233950 6422 master.cpp:2869] Received SUBSCRIBE call for
framework 'default' at
scheduler-45fd4720-32c6-484c-9453-8b394ef5f431@172.17.0.5:45258
I0207 15:16:31.234025 6422 master.cpp:2198] Authorizing framework principal
'test-principal' to receive offers for roles '{ default-role }'
I0207 15:16:31.234517 6432 master.cpp:2949] Subscribing framework default with
checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT,
SHARED_RESOURCES ]
I0207 15:16:31.234709 6432 master.cpp:9199] Adding framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000 (default) at
scheduler-45fd4720-32c6-484c-9453-8b394ef5f431@172.17.0.5:45258 with roles { }
suppressed
I0207 15:16:31.235157 6436 sched.cpp:751] Framework registered with
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.235199 6436 sched.cpp:765] Scheduler::registered took 17967ns
I0207 15:16:31.235272 6429 hierarchical.cpp:297] Added framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.236976 6429 hierarchical.cpp:1517] Performed allocation for 1
agents in 1.573051ms
I0207 15:16:31.237663 6424 master.cpp:8808] Sending 1 offers to framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000 (default) at
scheduler-45fd4720-32c6-484c-9453-8b394ef5f431@172.17.0.5:45258
I0207 15:16:31.238255 6428 sched.cpp:921] Scheduler::resourceOffers took
93539ns
I0207 15:16:31.240391 6434 master.cpp:10716] Removing offer
b49ee98d-474d-4274-80cd-a325f49f7a20-O0
I0207 15:16:31.240959 6434 master.cpp:4220] Processing ACCEPT call for offers:
[ b49ee98d-474d-4274-80cd-a325f49f7a20-O0 ] on agent
b49ee98d-474d-4274-80cd-a325f49f7a20-S0 at slave(905)@172.17.0.5:45258
(41fc79203ff5) for framework b49ee98d-474d-4274-80cd-a325f49f7a20-0000
(default) at scheduler-45fd4720-32c6-484c-9453-8b394ef5f431@172.17.0.5:45258
I0207 15:16:31.241096 6434 master.cpp:3708] 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_SharedPersistentVolumeMultipleIterations_3_mgPnpE\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"}]'
I0207 15:16:31.241608 6434 master.cpp:3505] Authorizing framework principal
'test-principal' to launch task f7749dac-42cf-4803-b732-763ca4a216ed
I0207 15:16:31.243108 6435 master.cpp:4696] Applying CREATE operation for
volumes
[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"}]
from framework b49ee98d-474d-4274-80cd-a325f49f7a20-0000 (default) at
scheduler-45fd4720-32c6-484c-9453-8b394ef5f431@172.17.0.5:45258 to agent
b49ee98d-474d-4274-80cd-a325f49f7a20-S0 at slave(905)@172.17.0.5:45258
(41fc79203ff5)
I0207 15:16:31.243852 6435 master.cpp:10614] Sending operation '' (uuid:
d318486d-4c3d-40cc-9a50-9cc4b63795b6) to agent
b49ee98d-474d-4274-80cd-a325f49f7a20-S0 at slave(905)@172.17.0.5:45258
(41fc79203ff5)
I0207 15:16:31.245482 6432 slave.cpp:3760] Updated checkpointed resources from
{} to disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<1>
I0207 15:16:31.245510 6435 master.cpp:11518] Adding task
f7749dac-42cf-4803-b732-763ca4a216ed with resources cpus(allocated:
default-role):1; mem(allocated: default-role):128; disk(allocated:
default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<1>
on agent b49ee98d-474d-4274-80cd-a325f49f7a20-S0 at
slave(905)@172.17.0.5:45258 (41fc79203ff5)
I0207 15:16:31.245594 6432 slave.cpp:7513] Updating the state of operation '
with no ID (uuid: d318486d-4c3d-40cc-9a50-9cc4b63795b6) for framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000 (latest state: OPERATION_FINISHED,
status update state: OPERATION_FINISHED)
I0207 15:16:31.245968 6435 master.cpp:4964] Launching task
f7749dac-42cf-4803-b732-763ca4a216ed of framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000 (default) at
scheduler-45fd4720-32c6-484c-9453-8b394ef5f431@172.17.0.5:45258 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"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE\/disk1"},"type":"PATH"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"}]
on agent b49ee98d-474d-4274-80cd-a325f49f7a20-S0 at
slave(905)@172.17.0.5:45258 (41fc79203ff5)
I0207 15:16:31.247239 6435 master.cpp:10374] Updating the state of operation
'' (uuid: d318486d-4c3d-40cc-9a50-9cc4b63795b6) for framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000 (latest state: OPERATION_PENDING,
status update state: OPERATION_FINISHED)
I0207 15:16:31.248091 6430 slave.cpp:1879] Got assigned task
'f7749dac-42cf-4803-b732-763ca4a216ed' for framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.248998 6430 slave.cpp:2149] Authorizing task
'f7749dac-42cf-4803-b732-763ca4a216ed' for framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.249089 6430 slave.cpp:7955] Authorizing framework principal
'test-principal' to launch task f7749dac-42cf-4803-b732-763ca4a216ed
I0207 15:16:31.250663 6428 slave.cpp:2542] Launching task
'f7749dac-42cf-4803-b732-763ca4a216ed' for framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.250777 6428 paths.cpp:727] Creating sandbox
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS/slaves/b49ee98d-474d-4274-80cd-a325f49f7a20-S0/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/f7749dac-42cf-4803-b732-763ca4a216ed/runs/8f07de16-32cb-409a-816a-b8c7cb270eda'
for user 'mesos'
I0207 15:16:31.251751 6428 slave.cpp:8429] Launching executor
'f7749dac-42cf-4803-b732-763ca4a216ed' of framework
b49ee98d-474d-4274-80cd-a325f49f7a20-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_SharedPersistentVolumeMultipleIterations_3_sFgbvS/slaves/b49ee98d-474d-4274-80cd-a325f49f7a20-S0/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/f7749dac-42cf-4803-b732-763ca4a216ed/runs/8f07de16-32cb-409a-816a-b8c7cb270eda'
I0207 15:16:31.252411 6436 hierarchical.cpp:925] Updated allocation of
framework b49ee98d-474d-4274-80cd-a325f49f7a20-0000 on agent
b49ee98d-474d-4274-80cd-a325f49f7a20-S0 from cpus(allocated: default-role):2;
mem(allocated: default-role):2048; disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1]:2048;
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/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_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk2]:2048;
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<1>
I0207 15:16:31.252856 6428 slave.cpp:3102] Launching container
8f07de16-32cb-409a-816a-b8c7cb270eda for executor
'f7749dac-42cf-4803-b732-763ca4a216ed' of framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.253696 6428 slave.cpp:2628] Queued task
'f7749dac-42cf-4803-b732-763ca4a216ed' for executor
'f7749dac-42cf-4803-b732-763ca4a216ed' of framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.253824 6428 slave.cpp:1006] Successfully attached
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS/slaves/b49ee98d-474d-4274-80cd-a325f49f7a20-S0/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/f7749dac-42cf-4803-b732-763ca4a216ed/runs/8f07de16-32cb-409a-816a-b8c7cb270eda'
to virtual path
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS/slaves/b49ee98d-474d-4274-80cd-a325f49f7a20-S0/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/f7749dac-42cf-4803-b732-763ca4a216ed/runs/latest'
I0207 15:16:31.253808 6436 hierarchical.cpp:1192] 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_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk2]:2048
(total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk2]:2048;
disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<1>,
allocated: cpus(allocated: default-role):1; mem(allocated: default-role):128;
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<1>)
on agent b49ee98d-474d-4274-80cd-a325f49f7a20-S0 from framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.253888 6428 slave.cpp:1006] Successfully attached
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS/slaves/b49ee98d-474d-4274-80cd-a325f49f7a20-S0/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/f7749dac-42cf-4803-b732-763ca4a216ed/runs/8f07de16-32cb-409a-816a-b8c7cb270eda'
to virtual path
'/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/f7749dac-42cf-4803-b732-763ca4a216ed/runs/latest'
I0207 15:16:31.253942 6428 slave.cpp:1006] Successfully attached
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS/slaves/b49ee98d-474d-4274-80cd-a325f49f7a20-S0/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/f7749dac-42cf-4803-b732-763ca4a216ed/runs/8f07de16-32cb-409a-816a-b8c7cb270eda'
to virtual path
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS/slaves/b49ee98d-474d-4274-80cd-a325f49f7a20-S0/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/f7749dac-42cf-4803-b732-763ca4a216ed/runs/8f07de16-32cb-409a-816a-b8c7cb270eda'
I0207 15:16:31.254359 6431 containerizer.cpp:1202] Starting container
8f07de16-32cb-409a-816a-b8c7cb270eda
I0207 15:16:31.255461 6431 containerizer.cpp:1368] Checkpointed
ContainerConfig at
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_IBHZA6/containers/8f07de16-32cb-409a-816a-b8c7cb270eda/config'
I0207 15:16:31.255493 6431 containerizer.cpp:2952] Transitioning the state of
container 8f07de16-32cb-409a-816a-b8c7cb270eda from PROVISIONING to PREPARING
I0207 15:16:31.256157 6434 posix.cpp:213] Changing the ownership of the
persistent volume at
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1/volumes/roles/default-role/id1'
with uid 1000 and gid 1000
I0207 15:16:31.256232 6434 posix.cpp:259] Adding symlink from
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1/volumes/roles/default-role/id1'
to
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS/slaves/b49ee98d-474d-4274-80cd-a325f49f7a20-S0/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/f7749dac-42cf-4803-b732-763ca4a216ed/runs/8f07de16-32cb-409a-816a-b8c7cb270eda/path1'
for persistent volume disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048
of container 8f07de16-32cb-409a-816a-b8c7cb270eda
I0207 15:16:31.260900 6424 containerizer.cpp:1844] Launching
'mesos-containerizer' with flags '--help="false"
--launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=\/mesos\/mesos-1.6.0\/_build\/src"],"shell":false,"value":"\/mesos\/mesos-1.6.0\/_build\/src\/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.5:45258"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS\/slaves\/b49ee98d-474d-4274-80cd-a325f49f7a20-S0\/frameworks\/b49ee98d-474d-4274-80cd-a325f49f7a20-0000\/executors\/f7749dac-42cf-4803-b732-763ca4a216ed\/runs\/8f07de16-32cb-409a-816a-b8c7cb270eda"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"f7749dac-42cf-4803-b732-763ca4a216ed"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"b49ee98d-474d-4274-80cd-a325f49f7a20-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"b49ee98d-474d-4274-80cd-a325f49f7a20-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(905)@172.17.0.5:45258"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS\/slaves\/b49ee98d-474d-4274-80cd-a325f49f7a20-S0\/frameworks\/b49ee98d-474d-4274-80cd-a325f49f7a20-0000\/executors\/f7749dac-42cf-4803-b732-763ca4a216ed\/runs\/8f07de16-32cb-409a-816a-b8c7cb270eda"}]},"task_environment":{},"user":"mesos","working_directory":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS\/slaves\/b49ee98d-474d-4274-80cd-a325f49f7a20-S0\/frameworks\/b49ee98d-474d-4274-80cd-a325f49f7a20-0000\/executors\/f7749dac-42cf-4803-b732-763ca4a216ed\/runs\/8f07de16-32cb-409a-816a-b8c7cb270eda"}"
--pipe_read="24" --pipe_write="26"
--runtime_directory="/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_IBHZA6/containers/8f07de16-32cb-409a-816a-b8c7cb270eda"
--unshare_namespace_mnt="false"'
I0207 15:16:31.267921 6424 launcher.cpp:140] Forked child with pid '15300' for
container '8f07de16-32cb-409a-816a-b8c7cb270eda'
I0207 15:16:31.268846 6424 containerizer.cpp:2952] Transitioning the state of
container 8f07de16-32cb-409a-816a-b8c7cb270eda from PREPARING to ISOLATING
I0207 15:16:31.271077 6430 containerizer.cpp:2952] Transitioning the state of
container 8f07de16-32cb-409a-816a-b8c7cb270eda from ISOLATING to FETCHING
I0207 15:16:31.271368 6430 fetcher.cpp:369] Starting to fetch URIs for
container: 8f07de16-32cb-409a-816a-b8c7cb270eda, directory:
/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS/slaves/b49ee98d-474d-4274-80cd-a325f49f7a20-S0/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/f7749dac-42cf-4803-b732-763ca4a216ed/runs/8f07de16-32cb-409a-816a-b8c7cb270eda
I0207 15:16:31.272588 6426 containerizer.cpp:2952] Transitioning the state of
container 8f07de16-32cb-409a-816a-b8c7cb270eda from FETCHING to RUNNING
I0207 15:16:31.277031 6422 hierarchical.cpp:1517] Performed allocation for 1
agents in 1.914081ms
I0207 15:16:31.277801 6434 master.cpp:8808] Sending 1 offers to framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000 (default) at
scheduler-45fd4720-32c6-484c-9453-8b394ef5f431@172.17.0.5:45258
I0207 15:16:31.278800 6435 sched.cpp:921] Scheduler::resourceOffers took
173955ns
I0207 15:16:31.281496 6425 master.cpp:10716] Removing offer
b49ee98d-474d-4274-80cd-a325f49f7a20-O1
I0207 15:16:31.282218 6425 master.cpp:4220] Processing ACCEPT call for offers:
[ b49ee98d-474d-4274-80cd-a325f49f7a20-O1 ] on agent
b49ee98d-474d-4274-80cd-a325f49f7a20-S0 at slave(905)@172.17.0.5:45258
(41fc79203ff5) for framework b49ee98d-474d-4274-80cd-a325f49f7a20-0000
(default) at scheduler-45fd4720-32c6-484c-9453-8b394ef5f431@172.17.0.5:45258
I0207 15:16:31.282415 6425 master.cpp:3708] Authorizing principal
'test-principal' to create volumes
'[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id2","principal":"test-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE\/disk2"},"type":"PATH"},"volume":{"container_path":"path2","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"}]'
I0207 15:16:31.282999 6425 master.cpp:3505] Authorizing framework principal
'test-principal' to launch task 2d59da0f-6df2-4061-b66e-8cebe157f360
I0207 15:16:31.285149 6430 master.cpp:4696] Applying CREATE operation for
volumes
[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"id2","principal":"test-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE\/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 b49ee98d-474d-4274-80cd-a325f49f7a20-0000 (default) at
scheduler-45fd4720-32c6-484c-9453-8b394ef5f431@172.17.0.5:45258 to agent
b49ee98d-474d-4274-80cd-a325f49f7a20-S0 at slave(905)@172.17.0.5:45258
(41fc79203ff5)
I0207 15:16:31.286317 6430 master.cpp:10614] Sending operation '' (uuid:
bb9287a1-13ed-448a-b1d8-018413fd2359) to agent
b49ee98d-474d-4274-80cd-a325f49f7a20-S0 at slave(905)@172.17.0.5:45258
(41fc79203ff5)
I0207 15:16:31.288663 6430 master.cpp:11518] Adding task
2d59da0f-6df2-4061-b66e-8cebe157f360 with resources cpus(allocated:
default-role):1; mem(allocated: default-role):128; disk(allocated:
default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk2,id2:path2]<SHARED>:2048<1>
on agent b49ee98d-474d-4274-80cd-a325f49f7a20-S0 at
slave(905)@172.17.0.5:45258 (41fc79203ff5)
I0207 15:16:31.289186 6421 slave.cpp:3760] Updated checkpointed resources from
disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<1>
to disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<1>;
disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk2,id2:path2]<SHARED>:2048<1>
I0207 15:16:31.289369 6421 slave.cpp:7513] Updating the state of operation '
with no ID (uuid: bb9287a1-13ed-448a-b1d8-018413fd2359) for framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000 (latest state: OPERATION_FINISHED,
status update state: OPERATION_FINISHED)
I0207 15:16:31.289266 6430 master.cpp:4964] Launching task
2d59da0f-6df2-4061-b66e-8cebe157f360 of framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000 (default) at
scheduler-45fd4720-32c6-484c-9453-8b394ef5f431@172.17.0.5:45258 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":"id2","principal":"test-principal"},"source":{"path":{"root":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE\/disk2"},"type":"PATH"},"volume":{"container_path":"path2","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":2048.0},"shared":{},"type":"SCALAR"}]
on agent b49ee98d-474d-4274-80cd-a325f49f7a20-S0 at
slave(905)@172.17.0.5:45258 (41fc79203ff5)
I0207 15:16:31.290248 6430 master.cpp:10374] Updating the state of operation
'' (uuid: bb9287a1-13ed-448a-b1d8-018413fd2359) for framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000 (latest state: OPERATION_PENDING,
status update state: OPERATION_FINISHED)
I0207 15:16:31.290778 6436 slave.cpp:1879] Got assigned task
'2d59da0f-6df2-4061-b66e-8cebe157f360' for framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.291436 6436 slave.cpp:2149] Authorizing task
'2d59da0f-6df2-4061-b66e-8cebe157f360' for framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.291501 6436 slave.cpp:7955] Authorizing framework principal
'test-principal' to launch task 2d59da0f-6df2-4061-b66e-8cebe157f360
I0207 15:16:31.292733 6435 slave.cpp:2542] Launching task
'2d59da0f-6df2-4061-b66e-8cebe157f360' for framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.292842 6435 paths.cpp:727] Creating sandbox
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS/slaves/b49ee98d-474d-4274-80cd-a325f49f7a20-S0/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/2d59da0f-6df2-4061-b66e-8cebe157f360/runs/df0541ec-9967-422b-ad50-a7d1726525ec'
for user 'mesos'
I0207 15:16:31.293505 6435 slave.cpp:8429] Launching executor
'2d59da0f-6df2-4061-b66e-8cebe157f360' of framework
b49ee98d-474d-4274-80cd-a325f49f7a20-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_SharedPersistentVolumeMultipleIterations_3_sFgbvS/slaves/b49ee98d-474d-4274-80cd-a325f49f7a20-S0/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/2d59da0f-6df2-4061-b66e-8cebe157f360/runs/df0541ec-9967-422b-ad50-a7d1726525ec'
I0207 15:16:31.294456 6435 slave.cpp:3102] Launching container
df0541ec-9967-422b-ad50-a7d1726525ec for executor
'2d59da0f-6df2-4061-b66e-8cebe157f360' of framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.295352 6435 slave.cpp:2628] Queued task
'2d59da0f-6df2-4061-b66e-8cebe157f360' for executor
'2d59da0f-6df2-4061-b66e-8cebe157f360' of framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.295485 6435 slave.cpp:1006] Successfully attached
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS/slaves/b49ee98d-474d-4274-80cd-a325f49f7a20-S0/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/2d59da0f-6df2-4061-b66e-8cebe157f360/runs/df0541ec-9967-422b-ad50-a7d1726525ec'
to virtual path
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS/slaves/b49ee98d-474d-4274-80cd-a325f49f7a20-S0/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/2d59da0f-6df2-4061-b66e-8cebe157f360/runs/latest'
I0207 15:16:31.295547 6435 slave.cpp:1006] Successfully attached
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS/slaves/b49ee98d-474d-4274-80cd-a325f49f7a20-S0/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/2d59da0f-6df2-4061-b66e-8cebe157f360/runs/df0541ec-9967-422b-ad50-a7d1726525ec'
to virtual path
'/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/2d59da0f-6df2-4061-b66e-8cebe157f360/runs/latest'
I0207 15:16:31.295593 6435 slave.cpp:1006] Successfully attached
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS/slaves/b49ee98d-474d-4274-80cd-a325f49f7a20-S0/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/2d59da0f-6df2-4061-b66e-8cebe157f360/runs/df0541ec-9967-422b-ad50-a7d1726525ec'
to virtual path
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS/slaves/b49ee98d-474d-4274-80cd-a325f49f7a20-S0/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/2d59da0f-6df2-4061-b66e-8cebe157f360/runs/df0541ec-9967-422b-ad50-a7d1726525ec'
I0207 15:16:31.295867 6428 hierarchical.cpp:925] Updated allocation of
framework b49ee98d-474d-4274-80cd-a325f49f7a20-0000 on agent
b49ee98d-474d-4274-80cd-a325f49f7a20-S0 from cpus(allocated: default-role):2;
mem(allocated: default-role):2048; disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<2>;
ports(allocated: default-role):[31000-32000]; disk(allocated:
default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk2]:2048
to cpus(allocated: default-role):2; mem(allocated: default-role):2048;
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<2>;
ports(allocated: default-role):[31000-32000]; disk(allocated:
default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk2,id2:path2]<SHARED>:2048<1>
I0207 15:16:31.295990 6423 containerizer.cpp:1202] Starting container
df0541ec-9967-422b-ad50-a7d1726525ec
I0207 15:16:31.297499 6423 containerizer.cpp:1368] Checkpointed
ContainerConfig at
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_IBHZA6/containers/df0541ec-9967-422b-ad50-a7d1726525ec/config'
I0207 15:16:31.297543 6423 containerizer.cpp:2952] Transitioning the state of
container df0541ec-9967-422b-ad50-a7d1726525ec from PROVISIONING to PREPARING
I0207 15:16:31.297483 6428 hierarchical.cpp:1192] Recovered disk(allocated:
default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<1>;
mem(allocated: default-role):1792; ports(allocated:
default-role):[31000-32000] (total: cpus:2; mem:2048; ports:[31000-32000];
disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<1>;
disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk2,id2:path2]<SHARED>:2048<1>,
allocated: cpus(allocated: default-role):2; mem(allocated: default-role):256;
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<1>;
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk2,id2:path2]<SHARED>:2048<1>)
on agent b49ee98d-474d-4274-80cd-a325f49f7a20-S0 from framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.298305 6425 posix.cpp:213] Changing the ownership of the
persistent volume at
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk2/volumes/roles/default-role/id2'
with uid 1000 and gid 1000
I0207 15:16:31.298401 6425 posix.cpp:259] Adding symlink from
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk2/volumes/roles/default-role/id2'
to
'/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS/slaves/b49ee98d-474d-4274-80cd-a325f49f7a20-S0/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/2d59da0f-6df2-4061-b66e-8cebe157f360/runs/df0541ec-9967-422b-ad50-a7d1726525ec/path2'
for persistent volume disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk2,id2:path2]<SHARED>:2048
of container df0541ec-9967-422b-ad50-a7d1726525ec
I0207 15:16:31.302985 6431 containerizer.cpp:1844] Launching
'mesos-containerizer' with flags '--help="false"
--launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=\/mesos\/mesos-1.6.0\/_build\/src"],"shell":false,"value":"\/mesos\/mesos-1.6.0\/_build\/src\/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.5:45258"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS\/slaves\/b49ee98d-474d-4274-80cd-a325f49f7a20-S0\/frameworks\/b49ee98d-474d-4274-80cd-a325f49f7a20-0000\/executors\/2d59da0f-6df2-4061-b66e-8cebe157f360\/runs\/df0541ec-9967-422b-ad50-a7d1726525ec"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"2d59da0f-6df2-4061-b66e-8cebe157f360"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"b49ee98d-474d-4274-80cd-a325f49f7a20-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"b49ee98d-474d-4274-80cd-a325f49f7a20-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(905)@172.17.0.5:45258"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS\/slaves\/b49ee98d-474d-4274-80cd-a325f49f7a20-S0\/frameworks\/b49ee98d-474d-4274-80cd-a325f49f7a20-0000\/executors\/2d59da0f-6df2-4061-b66e-8cebe157f360\/runs\/df0541ec-9967-422b-ad50-a7d1726525ec"}]},"task_environment":{},"user":"mesos","working_directory":"\/tmp\/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS\/slaves\/b49ee98d-474d-4274-80cd-a325f49f7a20-S0\/frameworks\/b49ee98d-474d-4274-80cd-a325f49f7a20-0000\/executors\/2d59da0f-6df2-4061-b66e-8cebe157f360\/runs\/df0541ec-9967-422b-ad50-a7d1726525ec"}"
--pipe_read="24" --pipe_write="26"
--runtime_directory="/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_IBHZA6/containers/df0541ec-9967-422b-ad50-a7d1726525ec"
--unshare_namespace_mnt="false"'
I0207 15:16:31.308357 6431 launcher.cpp:140] Forked child with pid '15301' for
container 'df0541ec-9967-422b-ad50-a7d1726525ec'
I0207 15:16:31.309190 6431 containerizer.cpp:2952] Transitioning the state of
container df0541ec-9967-422b-ad50-a7d1726525ec from PREPARING to ISOLATING
I0207 15:16:31.311614 6421 containerizer.cpp:2952] Transitioning the state of
container df0541ec-9967-422b-ad50-a7d1726525ec from ISOLATING to FETCHING
I0207 15:16:31.312024 6436 fetcher.cpp:369] Starting to fetch URIs for
container: df0541ec-9967-422b-ad50-a7d1726525ec, directory:
/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_sFgbvS/slaves/b49ee98d-474d-4274-80cd-a325f49f7a20-S0/frameworks/b49ee98d-474d-4274-80cd-a325f49f7a20-0000/executors/2d59da0f-6df2-4061-b66e-8cebe157f360/runs/df0541ec-9967-422b-ad50-a7d1726525ec
I0207 15:16:31.313030 6422 containerizer.cpp:2952] Transitioning the state of
container df0541ec-9967-422b-ad50-a7d1726525ec from FETCHING to RUNNING
I0207 15:16:31.317934 6429 hierarchical.cpp:1517] Performed allocation for 1
agents in 2.626095ms
I0207 15:16:31.319011 6425 master.cpp:8808] Sending 1 offers to framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000 (default) at
scheduler-45fd4720-32c6-484c-9453-8b394ef5f431@172.17.0.5:45258
I0207 15:16:31.319983 6423 sched.cpp:921] Scheduler::resourceOffers took
162918ns
I0207 15:16:31.320562 6420 sched.cpp:2009] Asked to stop the driver
I0207 15:16:31.320750 6431 sched.cpp:1191] Stopping framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.321113 6433 master.cpp:9488] Processing TEARDOWN call for
framework b49ee98d-474d-4274-80cd-a325f49f7a20-0000 (default) at
scheduler-45fd4720-32c6-484c-9453-8b394ef5f431@172.17.0.5:45258
I0207 15:16:31.321235 6433 master.cpp:9500] Removing framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000 (default) at
scheduler-45fd4720-32c6-484c-9453-8b394ef5f431@172.17.0.5:45258
I0207 15:16:31.321265 6433 master.cpp:3239] Deactivating framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000 (default) at
scheduler-45fd4720-32c6-484c-9453-8b394ef5f431@172.17.0.5:45258
I0207 15:16:31.321451 6427 hierarchical.cpp:405] Deactivated framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.322427 6425 slave.cpp:931] Agent terminating
I0207 15:16:31.322492 6425 slave.cpp:3454] Asked to shut down framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000 by @0.0.0.0:0
I0207 15:16:31.322523 6425 slave.cpp:3479] Shutting down framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.322563 6433 master.cpp:10716] Removing offer
b49ee98d-474d-4274-80cd-a325f49f7a20-O2
I0207 15:16:31.322582 6425 slave.cpp:6178] Shutting down executor
'f7749dac-42cf-4803-b732-763ca4a216ed' of framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
W0207 15:16:31.322597 6425 slave.hpp:882] Unable to send event to executor
'f7749dac-42cf-4803-b732-763ca4a216ed' of framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000: unknown connection type
I0207 15:16:31.322679 6425 slave.cpp:6178] Shutting down executor
'2d59da0f-6df2-4061-b66e-8cebe157f360' of framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
W0207 15:16:31.322696 6425 slave.hpp:882] Unable to send event to executor
'2d59da0f-6df2-4061-b66e-8cebe157f360' of framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000: unknown connection type
I0207 15:16:31.322793 6433 master.cpp:10204] Updating the state of task
2d59da0f-6df2-4061-b66e-8cebe157f360 of framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000 (latest state: TASK_KILLED, status
update state: TASK_KILLED)
I0207 15:16:31.323117 6430 hierarchical.cpp:1192] Recovered ports(allocated:
default-role):[31000-32000]; mem(allocated: default-role):1792; disk(allocated:
default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<1>;
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk2,id2:path2]<SHARED>:2048<1>
(total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<1>;
disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk2,id2:path2]<SHARED>:2048<1>,
allocated: cpus(allocated: default-role):2; mem(allocated: default-role):256;
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<1>;
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk2,id2:path2]<SHARED>:2048<1>)
on agent b49ee98d-474d-4274-80cd-a325f49f7a20-S0 from framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.323577 6433 master.cpp:10303] Removing task
2d59da0f-6df2-4061-b66e-8cebe157f360 with resources cpus(allocated:
default-role):1; mem(allocated: default-role):128; disk(allocated:
default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk2,id2:path2]<SHARED>:2048<1>
of framework b49ee98d-474d-4274-80cd-a325f49f7a20-0000 on agent
b49ee98d-474d-4274-80cd-a325f49f7a20-S0 at slave(905)@172.17.0.5:45258
(41fc79203ff5)
I0207 15:16:31.323645 6434 containerizer.cpp:2338] Destroying container
8f07de16-32cb-409a-816a-b8c7cb270eda in RUNNING state
I0207 15:16:31.323681 6434 containerizer.cpp:2952] Transitioning the state of
container 8f07de16-32cb-409a-816a-b8c7cb270eda from RUNNING to DESTROYING
I0207 15:16:31.323834 6433 master.cpp:10204] Updating the state of task
f7749dac-42cf-4803-b732-763ca4a216ed of framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000 (latest state: TASK_KILLED, status
update state: TASK_KILLED)
I0207 15:16:31.324115 6434 launcher.cpp:156] Asked to destroy container
8f07de16-32cb-409a-816a-b8c7cb270eda
I0207 15:16:31.324388 6433 master.cpp:10303] Removing task
f7749dac-42cf-4803-b732-763ca4a216ed with resources cpus(allocated:
default-role):1; mem(allocated: default-role):128; disk(allocated:
default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<1>
of framework b49ee98d-474d-4274-80cd-a325f49f7a20-0000 on agent
b49ee98d-474d-4274-80cd-a325f49f7a20-S0 at slave(905)@172.17.0.5:45258
(41fc79203ff5)
I0207 15:16:31.324550 6430 hierarchical.cpp:1192] Recovered cpus(allocated:
default-role):1; mem(allocated: default-role):128; disk(allocated:
default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk2,id2:path2]<SHARED>:2048<1>
(total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<1>;
disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk2,id2:path2]<SHARED>:2048<1>,
allocated: cpus(allocated: default-role):1; mem(allocated: default-role):128;
disk(allocated: default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<1>)
on agent b49ee98d-474d-4274-80cd-a325f49f7a20-S0 from framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.324885 6433 master.cpp:1307] Agent
b49ee98d-474d-4274-80cd-a325f49f7a20-S0 at slave(905)@172.17.0.5:45258
(41fc79203ff5) disconnected
I0207 15:16:31.324915 6433 master.cpp:3276] Disconnecting agent
b49ee98d-474d-4274-80cd-a325f49f7a20-S0 at slave(905)@172.17.0.5:45258
(41fc79203ff5)
I0207 15:16:31.324970 6433 master.cpp:3295] Deactivating agent
b49ee98d-474d-4274-80cd-a325f49f7a20-S0 at slave(905)@172.17.0.5:45258
(41fc79203ff5)
I0207 15:16:31.325827 6430 hierarchical.cpp:1192] Recovered cpus(allocated:
default-role):1; mem(allocated: default-role):128; disk(allocated:
default-role)(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<1>
(total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk1,id1:path1]<SHARED>:2048<1>;
disk(reservations:
[(STATIC,default-role)])[PATH:/tmp/DiskResource_PersistentVolumeTest_SharedPersistentVolumeMultipleIterations_3_mgPnpE/disk2,id2:path2]<SHARED>:2048<1>,
allocated: {}) on agent b49ee98d-474d-4274-80cd-a325f49f7a20-S0 from framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.326220 6430 hierarchical.cpp:344] Removed framework
b49ee98d-474d-4274-80cd-a325f49f7a20-0000
I0207 15:16:31.326280 6430 hierarchical.cpp:766] Agent
b49ee98d-474d-4274-80cd-a325f49f7a20-S0 deactivated
I0207 15:16:31.424165 6426 containerizer.cpp:2791] Container
8f07de16-32cb-409a-816a-b8c7cb270eda has exited
I0207 15:16:31.427613 6423 provisioner.cpp:598] Ignoring destroy request for
unknown container 8f07de16-32cb-409a-816a-b8c7cb270eda
I0207 15:16:31.429425 6426 containerizer.cpp:2338] Destroying container
df0541ec-9967-422b-ad50-a7d1726525ec in RUNNING state
I0207 15:16:31.429466 6426 containerizer.cpp:2952] Transitioning the state of
container df0541ec-9967-422b-ad50-a7d1726525ec from RUNNING to DESTROYING
I0207 15:16:31.429895 6426 launcher.cpp:156] Asked to destroy container
df0541ec-9967-422b-ad50-a7d1726525ec
I0207 15:16:31.525626 6422 containerizer.cpp:2791] Container
df0541ec-9967-422b-ad50-a7d1726525ec has exited
I0207 15:16:31.528887 6424 provisioner.cpp:598] Ignoring destroy request for
unknown container df0541ec-9967-422b-ad50-a7d1726525ec
I0207 15:16:31.540282 6420 master.cpp:1149] Master terminating
I0207 15:16:31.542249 6429 hierarchical.cpp:609] Removed agent
b49ee98d-474d-4274-80cd-a325f49f7a20-S0
[ OK ]
DiskResource/PersistentVolumeTest.SharedPersistentVolumeMultipleIterations/3
(360 ms)
[ RUN ] DiskResource/PersistentVolumeTest.SlaveRecovery/0
I0207 15:16:31.551677 6420 cluster.cpp:172] Creating default 'local' authorizer
I0207 15:16:31.555156 6423 master.cpp:458] Master
38e86f0b-ca78-41e9-8418-3255153e01b8 (41fc79203ff5) started on 172.17.0.5:45258
I0207 15:16:31.555189 6423 master.cpp:460] 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/SgzabD/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"
--require_agent_domain="false" --root_submissions="true" --user_sorter="drf"
--version="false" --webui_dir="/mesos/mesos-1.6.0/_inst/share/mesos/webui"
--work_dir="/tmp/SgzabD/master" --zk_session_timeout="10secs"
I0207 15:16:31.555644 6423 master.cpp:509] Master only allowing authenticated
frameworks to register
I0207 15:16:31.555658 6423 master.cpp:515] Master only allowing authenticated
agents to register
I0207 15:16:31.555666 6423 master.cpp:521] Master only allowing authenticated
HTTP frameworks to register
I0207 15:16:31.555676 6423 credentials.hpp:37] Loading credentials for
authentication from '/tmp/SgzabD/credentials'
I0207 15:16:31.556027 6423 master.cpp:565] Using default 'crammd5'
authenticator
I0207 15:16:31.556219 6423 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readonly'
I0207 15:16:31.556453 6423 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readwrite'
I0207 15:16:31.556635 6423 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-scheduler'
I0207 15:16:31.556821 6423 master.cpp:644] Authorization enabled
I0207 15:16:31.557056 6422 hierarchical.cpp:175] Initialized hierarchical
allocator process
I0207 15:16:31.557094 6433 whitelist_watcher.cpp:77] No whitelist given
I0207 15:16:31.560648 6428 master.cpp:2133] Elected as the leading master!
I0207 15:16:31.560686 6428 master.cpp:1692] Recovering from registrar
I0207 15:16:31.560950 6421 registrar.cpp:347] Recovering registrar
I0207 15:16:31.561542 6435 registrar.cpp:391] Successfully fetched the
registry (0B) in 537856ns
I0207 15:16:31.561688 6435 registrar.cpp:495] Applied 1 operations in 40681ns;
attempting to update the registry
I0207 15:16:31.562454 6435 registrar.cpp:552] Successfully updated the
registry in 696064ns
I0207 15:16:31.562610 6435 registrar.cpp:424] Successfully recovered registrar
I0207 15:16:31.563149 6428 hierarchical.cpp:213] Skipping recovery of
hierarchical allocator: nothing to recover
I0207 15:16:31.563165 6431 master.cpp:1806] Recovered 0 agents from the
registry (135B); allowing 10mins for agents to re-register
W0207 15:16:31.568683 6420 process.cpp:2805] Attempted to spawn already
running process files@172.17.0.5:45258
I0207 15:16:31.569756 6420 containerizer.cpp:304] Using isolation {
environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0207 15:16:31.570446 6420 backend.cpp:76] Failed to create 'aufs' backend:
AufsBackend requires root privileges
W0207 15:16:31.570591 6420 backend.cpp:76] Failed to create 'bind' backend:
BindBackend requires root privileges
I0207 15:16:31.570636 6420 provisioner.cpp:299] Using default backend 'copy'
I0207 15:16:31.572877 6420 cluster.cpp:460] Creating default 'local' authorizer
I0207 15:16:31.575811 6422 slave.cpp:262] Mesos agent started on
(906)@172.17.0.5:45258
I0207 15:16:31.575842 6422 slave.cpp:263] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/DiskResource_PersistentVolumeTest_SlaveRecovery_0_wrqEhm/store/appc"
--authenticate_http_readonly="true" --authenticate_http_readwrite="false"
--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_SlaveRecovery_0_wrqEhm/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_SlaveRecovery_0_wrqEhm/store/docker"
--docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume"
--enforce_container_disk_quota="false" --executor_registration_timeout="1mins"
--executor_reregistration_timeout="2secs"
--executor_shutdown_grace_period="5secs"
--fetcher_cache_dir="/tmp/DiskResource_PersistentVolumeTest_SlaveRecovery_0_wrqEhm/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_SlaveRecovery_0_wrqEhm/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem" --launcher="posix"
--launcher_dir="/mesos/mesos-1.6.0/_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" --reconfiguration_policy="equal" --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_SlaveRecovery_0_wrqEhm"
--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_SlaveRecovery_0_0LkCe7"
--zk_session_timeout="10secs"
I0207 15:16:31.576489 6422 credentials.hpp:86] Loading credential for
authentication from
'/tmp/DiskResource_PersistentVolumeTest_SlaveRecovery_0_wrqEhm/credential'
W0207 15:16:31.576560 6420 process.cpp:2805] Attempted to spawn already
running process version@172.17.0.5:45258
I0207 15:16:31.576720 6422 slave.cpp:295] Agent using credential for:
test-principal
I0207 15:16:31.576755 6422 credentials.hpp:37] Loading credentials for
authentication from
'/tmp/DiskResource_PersistentVolumeTest_SlaveRecovery_0_wrqEhm/http_credentials'
I0207 15:16:31.577039 6422 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
I0207 15:16:31.577808 6420 sched.cpp:232] Version: 1.6.0
I0207 15:16:31.578490 6423 sched.cpp:336] New master detected at
master@172.17.0.5:45258
I0207 15:16:31.578670 6423 sched.cpp:396] Authenticating with master
master@172.17.0.5:45258
I0207 15:16:31.578703 6423 sched.cpp:403] Using default CRAM-MD5 authenticatee
I0207 15:16:31.579044 6435 authenticatee.cpp:121] Creating new client SASL
connection
I0207 15:16:31.579454 6423 master.cpp:8978] Authenticating
scheduler-f51d9212-6b0b-46a5-bf30-bf8eb9c7fc59@172.17.0.5:45258
I0207 15:16:31.579685 6428 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1605)@172.17.0.5:45258
I0207 15:16:31.579960 6431 authenticator.cpp:98] Creating new server SASL
connection
I0207 15:16:31.580260 6430 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I0207 15:16:31.580292 6430 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0207 15:16:31.580394 6430 authenticator.cpp:204] Received SASL authentication
start
I0207 15:16:31.580176 6422 slave.cpp:612] 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"}]
I0207 15:16:31.580454 6430 authenticator.cpp:326] Authentication requires more
steps
I0207 15:16:31.580487 6422 slave.cpp:620] Agent attributes: [ ]
I0207 15:16:31.580505 6422 slave.cpp:629] Agent hostname: 41fc79203ff5
I0207 15:16:31.580620 6424 authenticatee.cpp:259] Received SASL authentication
step
I0207 15:16:31.580662 6421 task_status_update_manager.cpp:181] Pausing sending
task status updates
I0207 15:16:31.580760 6421 authenticator.cpp:232] Received SASL authentication
step
I0207 15:16:31.580799 6421 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '41fc79203ff5' server FQDN: '41fc79203ff5'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I0207 15:16:31.580818 6421 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I0207 15:16:31.580862 6421 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0207 15:16:31.580893 6421 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '41fc79203ff5' server FQDN: '41fc79203ff5'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
I0207 15:16:31.580904 6421 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0207 15:16:31.580912 6421 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0207 15:16:31.580930 6421 authenticator.cpp:318] Authentication success
I0207 15:16:31.581050 6429 authenticatee.cpp:299] Authentication success
I0207 15:16:31.581116 6434 master.cpp:9008] Successfully authenticated
principal 'test-principal' at
scheduler-f51d9212-6b0b-46a5-bf30-bf8eb9c7fc59@172.17.0.5:45258
I0207 15:16:31.581163 6421 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1605)@172.17.0.5:45258
I0207 15:16:31.581418 6433 sched.cpp:502] Successfully authenticated with
master master@172.17.0.5:45258
I0207 15:16:31.581449 6433 sched.cpp:824] Sending SUBSCRIBE call to
master@172.17.0.5:45258
I0207 15:16:31.581595 6433 sched.cpp:857] Will retry registration in
767.437097ms if necessary
I0207 15:16:31.581889 6423 master.cpp:2869] Received SUBSCRIBE call for
framework 'default' at
scheduler-f51d9212-6b0b-46a5-bf30-bf8eb9c7fc59@172.17.0.5:45258
I0207 15:16:31.582003 6423 master.cpp:2198] Authorizing framework principal
'test-principal' to receive offers for roles '{ default-role }'
I0207 15:16:31.582690 6425 master.cpp:2949] Subscribing framework default with
checkpointing enabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0207 15:16:31.582870 6430 state.cpp:66] Recovering state from
'/tmp/DiskResource_PersistentVolumeTest_SlaveRecovery_0_0LkCe7/meta'
I0207 15:16:31.582960 6425 master.cpp:9199] Adding framework
38e86f0b-ca78-41e9-8418-3255153e01b8-0000 (default) at
scheduler-f51d9212-6b0b-46a5-bf30-bf8eb9c7fc59@172.17.0.5:45258 with roles { }
suppressed
I0207 15:16:31.583319 6430 task_status_update_manager.cpp:207] Recovering task
status update manager
I0207 15:16:31.583544 6435 sched.cpp:751] Framework registered with
38e86f0b-ca78-41e9-8418-3255153e01b8-0000
I0207 15:16:31.583642 6435 sched.cpp:765] Scheduler::registered took 68428ns
I0207 15:16:31.583680 6433 containerizer.cpp:674] Recovering containerizer
I0207 15:16:31.583725 6427 hierarchical.cpp:297] Added framework
38e86f0b-ca78-41e9-8418-3255153e01b8-0000
I0207 15:16:31.584007 6427 hierarchical.cpp:1517] Performed allocation for 0
agents in 92043ns
I0207 15:16:31.585662 6421 provisioner.cpp:495] Provisioner recovery complete
I0207 15:16:31.586143 6427 slave.cpp:6824] Finished recovery
I0207 15:16:31.587138 6424 task_status_update_manager.cpp:181] Pausing sending
task status updates
I0207 15:16:31.587211 6436 slave.cpp:1146] New master detected at
master@172.17.0.5:45258
I0207 15:16:31.587345 6436 slave.cpp:1201] Detecting new master
I0207 15:16:31.592862 6432 slave.cpp:1228] Authenticating with master
master@172.17.0.5:45258
I0207 15:16:31.592944 6432 slave.cpp:1237] Using default CRAM-MD5 authenticatee
I0207 15:16:31.593191 6429 authenticatee.cpp:121] Creating new client SASL
connection
I0207 15:16:31.593520 6433 master.cpp:8978] Authenticating
slave(906)@172.17.0.5:45258
I0207 15:16:31.593662 6423 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1606)@172.17.0.5:45258
I0207 15:16:31.593969 6430 authenticator.cpp:98] Creating new server SASL
connection
I0207 15:16:31.594239 6435 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I0207 15:16:31.594285 6435 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0207 15:16:31.594442 6431 authenticator.cpp:204] Received SASL authentication
start
I0207 15:16:31.594521 6431 authenticator.cpp:326] Authentication requires more
steps
I0207 15:16:31.594669 6422 authenticatee.cpp:259] Received SASL authentication
step
I0207 15:16:31.594825 6422 authenticator.cpp:232] Received SASL authentication
step
I0207 15:16:31.594869 6422 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '41fc79203ff5' server FQDN: '41fc79203ff5'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I0207 15:16:31.594890 6422 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I0207 15:16:31.594941 6422 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0207 15:16:31.594975 6422 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '41fc79203ff5' server FQDN: '41fc79203ff5'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
I0207 15:16:31.595000 6422 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0207 15:16:31.595016 6422 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0207 15:16:31.595047 6422 authenticator.cpp:318] Authentication success
I0207 15:16:31.595152 6428 authenticatee.cpp:299] Authentication success
I0207 15:16:31.595271 6427 maProcess leaked file descriptors. See
https://jenkins.io/redirect/troubleshooting/process-leaked-file-descriptors for
more informationster.cpp:9008] Successfully authenticated principal
'test-principal' at slave(906)@172.17.0.5:45258
I0207 15:16:31.595346 6428 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1606)@172.17.0.5:45258
I0207 15:16:31.595506 6434 slave.cpp:1320] Successfully authenticated with
master master@172.17.0.5:45258
I0207 15:16:31.595912 6434 slave.cpp:1766] Will retry registration in
16.453374ms if necessary
I0207 15:16:31.596122 6429 master.cpp:6013] Received register agent message
from slave(906)@172.17.0.5:45258 (41fc79203ff5)
I0207 15:16:31.596518 6429 master.cpp:3793] Authorizing agent providing
resources 'cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)]):4096;
ports:[31000-32000]' with principal 'test-principal'
I0207 15:16:31.596971 6429 master.cpp:3573] Authorizing principal
'test-principal' to reserve resources 'cpus:2; mem:2048; disk(reservations:
[(STATIC,default-role)]):4096; ports:[31000-32000]'
I0207 15:16:31.597973 6422 master.cpp:6084] Authorized registration of agent
at slave(906)@172.17.0.5:45258 (41fc79203ff5)
Build step 'Execute shell' marked build as failure
