Vinod Kone created MESOS-9458:
---------------------------------
Summary: PersistentVolumeEndpointsTest.StaticReservation is flaky
Key: MESOS-9458
URL: https://issues.apache.org/jira/browse/MESOS-9458
Project: Mesos
Issue Type: Bug
Components: allocation
Reporter: Vinod Kone
Observed this in ASF CI
https://builds.apache.org/view/M-R/view/Mesos/job/Mesos-Buildbot-Test/310/BUILDTOOL=autotools,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--disable-parallel-test-execution,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1%20MESOS_TEST_AWAIT_TIMEOUT=60secs,OS=ubuntu:16.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!ubuntu-4)&&(!H21)&&(!H23)&&(!H26)&&(!H27)/consoleText
{noformat}
[ RUN ] PersistentVolumeEndpointsTest.StaticReservation
I1205 11:34:05.896515 22538 cluster.cpp:173] Creating default 'local' authorizer
I1205 11:34:05.898870 22542 master.cpp:413] Master
3f2d828b-bff8-461a-98cf-de9163b36657 (488de0351206) started on 172.17.0.2:40803
I1205 11:34:05.898895 22542 master.cpp:416] Flags at startup: --acls=""
--agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
--allocation_interval="1000secs" --allocator="hierarchical"
--authenticate_agents="true" --authenticate_frameworks="true"
--authenticate_http_frameworks="true" --authenticate_http_readonly="true"
--authenticate_http_readwrite="true" --authentication_v0_timeout="15secs"
--authenticators="crammd5" --authorizers="local"
--credentials="/tmp/qOMyLF/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" --memory_profiling="false"
--min_allocatable_resources="cpus:0.01|mem:32" --port="5050"
--publish_per_framework_metrics="true" --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" --role_sorter="drf" --roles="role1"
--root_submissions="true" --version="false"
--webui_dir="/tmp/SRC/build/mesos-1.8.0/_inst/share/mesos/webui"
--work_dir="/tmp/qOMyLF/master" --zk_session_timeout="10secs"
I1205 11:34:05.899194 22542 master.cpp:465] Master only allowing authenticated
frameworks to register
I1205 11:34:05.899205 22542 master.cpp:471] Master only allowing authenticated
agents to register
I1205 11:34:05.899212 22542 master.cpp:477] Master only allowing authenticated
HTTP frameworks to register
I1205 11:34:05.899219 22542 credentials.hpp:37] Loading credentials for
authentication from '/tmp/qOMyLF/credentials'
I1205 11:34:05.899503 22542 master.cpp:521] Using default 'crammd5'
authenticator
I1205 11:34:05.899674 22542 http.cpp:1042] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readonly'
I1205 11:34:05.899879 22542 http.cpp:1042] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readwrite'
I1205 11:34:05.900029 22542 http.cpp:1042] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-scheduler'
I1205 11:34:05.900211 22542 master.cpp:602] Authorization enabled
W1205 11:34:05.900238 22542 master.cpp:665] The '--roles' flag is deprecated.
This flag will be removed in the future. See the Mesos 0.27 upgrade notes for
more information
I1205 11:34:05.900684 22539 hierarchical.cpp:175] Initialized hierarchical
allocator process
I1205 11:34:05.900707 22545 whitelist_watcher.cpp:77] No whitelist given
I1205 11:34:05.903553 22540 master.cpp:2105] Elected as the leading master!
I1205 11:34:05.903587 22540 master.cpp:1660] Recovering from registrar
I1205 11:34:05.903753 22551 registrar.cpp:339] Recovering registrar
I1205 11:34:05.904373 22551 registrar.cpp:383] Successfully fetched the
registry (0B) in 574976ns
I1205 11:34:05.904498 22551 registrar.cpp:487] Applied 1 operations in 34823ns;
attempting to update the registry
I1205 11:34:05.905134 22551 registrar.cpp:544] Successfully updated the
registry in 566016ns
I1205 11:34:05.905258 22551 registrar.cpp:416] Successfully recovered registrar
I1205 11:34:05.905829 22539 master.cpp:1774] Recovered 0 agents from the
registry (135B); allowing 10mins for agents to reregister
I1205 11:34:05.905889 22540 hierarchical.cpp:215] Skipping recovery of
hierarchical allocator: nothing to recover
W1205 11:34:05.918561 22538 process.cpp:2829] Attempted to spawn already
running process files@172.17.0.2:40803
I1205 11:34:05.919775 22538 containerizer.cpp:305] Using isolation {
environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W1205 11:34:05.920341 22538 backend.cpp:76] Failed to create 'aufs' backend:
AufsBackend requires root privileges
W1205 11:34:05.920368 22538 backend.cpp:76] Failed to create 'bind' backend:
BindBackend requires root privileges
I1205 11:34:05.920403 22538 provisioner.cpp:298] Using default backend 'copy'
I1205 11:34:05.922456 22538 cluster.cpp:485] Creating default 'local' authorizer
I1205 11:34:05.924229 22551 slave.cpp:267] Mesos agent started on
(391)@172.17.0.2:40803
I1205 11:34:05.924255 22551 slave.cpp:268] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/PersistentVolumeEndpointsTest_StaticReservation_GsJlvW/store/appc"
--authenticate_http_readonly="true" --authenticate_http_readwrite="false"
--authenticatee="crammd5" --authentication_backoff_factor="1secs"
--authentication_timeout_max="1mins" --authentication_timeout_min="5secs"
--authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgr:
oups_destroy_timeout="1mins" --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/PersistentVolumeEndpointsTest_StaticReservation_GsJlvW/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/PersistentVolumeEndpointsTest_StaticReservation_GsJlvW/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/PersistentVolumeEndpointsTest_StaticReservation_GsJlvW/fetch"
--fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins"
--frameworks_home="/tmp/PersistentVolumeEndpointsTest_StaticReservation_GsJlvW/frameworks"
--gc_delay="1weeks" --gc_disk_headroom="0.1"
--gc_non_executor_container_sandboxes="false" --help="false"
--hostname_lookup="true" --http_command_executor="false"
--http_credentials="/tmp/PersistentVolumeEndpointsTest_StaticReservation_GsJlvW/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem" --launcher="posix"
--launcher_dir="/tmp/SRC/build/mesos-1.8.0/_build/sub/src" --logbufsecs="0"
--logging_level="INFO" --max_completed_executors_per_framework="150"
--memory_profiling="false" --network_cni_metrics="true"
--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="disk(role1):1024" --revocable_cpu_low_priority="true"
--runtime_dir="/tmp/PersistentVolumeEndpointsTest_StaticReservation_GsJlvW"
--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/PersistentVolumeEndpointsTest_StaticReservation_KUwQ7i"
--zk_session_timeout="10secs"
I1205 11:34:05.924623 22551 credentials.hpp:86] Loading credential for
authentication from
'/tmp/PersistentVolumeEndpointsTest_StaticReservation_GsJlvW/credential'
I1205 11:34:05.924759 22551 slave.cpp:300] Agent using credential for:
test-principal
I1205 11:34:05.924782 22551 credentials.hpp:37] Loading credentials for
authentication from
'/tmp/PersistentVolumeEndpointsTest_StaticReservation_GsJlvW/http_credentials'
I1205 11:34:05.925012 22551 http.cpp:1042] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
I1205 11:34:05.925344 22551 disk_profile_adaptor.cpp:80] Creating default disk
profile adaptor module
I1205 11:34:05.926213 22551 slave.cpp:615] Agent resources:
[{"name":"disk","reservations":[{"role":"role1","type":"STATIC"}],"scalar":{"value":1024.0},"type":"SCALAR"},{"name":"cpus","scalar":{"value":16.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":47268.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I1205 11:34:05.926450 22551 slave.cpp:623] Agent attributes: [ ]
I1205 11:34:05.926475 22551 slave.cpp:632] Agent hostname: 488de0351206
I1205 11:34:05.926609 22546 task_status_update_manager.cpp:181] Pausing sending
task status updates
I1205 11:34:05.927865 22554 state.cpp:66] Recovering state from
'/tmp/PersistentVolumeEndpointsTest_StaticReservation_KUwQ7i/meta'
I1205 11:34:05.928030 22547 slave.cpp:6915] Finished recovering checkpointed
state from '/tmp/PersistentVolumeEndpointsTest_StaticReservation_KUwQ7i/meta',
beginning agent recovery
I1205 11:34:05.928176 22554 task_status_update_manager.cpp:207] Recovering task
status update manager
I1205 11:34:05.928462 22539 containerizer.cpp:727] Recovering Mesos containers
I1205 11:34:05.928768 22539 containerizer.cpp:1053] Recovering isolators
I1205 11:34:05.929344 22551 containerizer.cpp:1092] Recovering provisioner
I1205 11:34:05.929981 22547 provisioner.cpp:494] Provisioner recovery complete
I1205 11:34:05.930649 22552 composing.cpp:339] Finished recovering all
containerizers
I1205 11:34:05.930830 22549 slave.cpp:7144] Recovering executors
I1205 11:34:05.930968 22549 slave.cpp:7297] Finished recovery
I1205 11:34:05.931632 22539 task_status_update_manager.cpp:181] Pausing sending
task status updates
I1205 11:34:05.931668 22551 slave.cpp:1260] New master detected at
master@172.17.0.2:40803
I1205 11:34:05.931783 22551 slave.cpp:1325] Detecting new master
I1205 11:34:05.941160 22547 slave.cpp:1352] Authenticating with master
master@172.17.0.2:40803
I1205 11:34:05.941254 22547 slave.cpp:1361] Using default CRAM-MD5 authenticatee
I1205 11:34:05.941591 22542 authenticatee.cpp:121] Creating new client SASL
connection
I1205 11:34:05.941869 22546 master.cpp:9699] Authenticating
slave(391)@172.17.0.2:40803
I1205 11:34:05.942010 22544 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(818)@172.17.0.2:40803
I1205 11:34:05.942288 22550 authenticator.cpp:98] Creating new server SASL
connection
I1205 11:34:05.942530 22540 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I1205 11:34:05.942561 22540 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I1205 11:34:05.942692 22552 authenticator.cpp:204] Received SASL authentication
start
I1205 11:34:05.942765 22552 authenticator.cpp:326] Authentication requires more
steps
I1205 11:34:05.942904 22541 authenticatee.cpp:259] Received SASL authentication
step
I1205 11:34:05.943044 22543 authenticator.cpp:232] Received SASL authentication
step
I1205 11:34:05.943074 22543 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '488de0351206' server FQDN: '488de0351206'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I1205 11:34:05.943086 22543 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I1205 11:34:05.943125 22543 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I1205 11:34:05.943152 22543 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '488de0351206' server FQDN: '488de0351206'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
I1205 11:34:05.943167 22543 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I1205 11:34:05.943176 22543 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1205 11:34:05.943192 22543 authenticator.cpp:318] Authentication success
I1205 11:34:05.943276 22549 authenticatee.cpp:299] Authentication success
I1205 11:34:05.943369 22545 master.cpp:9731] Successfully authenticated
principal 'test-principal' at slave(391)@172.17.0.2:40803
I1205 11:34:05.943554 22539 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(818)@172.17.0.2:40803
I1205 11:34:05.943675 22548 slave.cpp:1452] Successfully authenticated with
master master@172.17.0.2:40803
I1205 11:34:05.944106 22548 slave.cpp:1883] Will retry registration in
6.875164ms if necessary
I1205 11:34:05.944315 22546 master.cpp:6650] Received register agent message
from slave(391)@172.17.0.2:40803 (488de0351206)
I1205 11:34:05.944648 22546 master.cpp:3986] Authorizing agent providing
resources 'disk(reservations: [(STATIC,role1)]):1024; cpus:16; mem:47268;
ports:[31000-32000]' with principal 'test-principal'
I1205 11:34:05.945024 22546 master.cpp:3631] Authorizing principal
'test-principal' to reserve resources 'disk(reservations:
[(STATIC,role1)]):1024; cpus:16; mem:47268; ports:[31000-32000]'
I1205 11:34:05.945719 22551 master.cpp:6717] Authorized registration of agent
at slave(391)@172.17.0.2:40803 (488de0351206)
I1205 11:34:05.945827 22551 master.cpp:6832] Registering agent at
slave(391)@172.17.0.2:40803 (488de0351206) with id
3f2d828b-bff8-461a-98cf-de9163b36657-S0
I1205 11:34:05.946513 22545 registrar.cpp:487] Applied 1 operations in
208242ns; attempting to update the registry
I1205 11:34:05.947114 22547 registrar.cpp:544] Successfully updated the
registry in 530944ns
I1205 11:34:05.947335 22548 master.cpp:6880] Admitted agent
3f2d828b-bff8-461a-98cf-de9163b36657-S0 at slave(391)@172.17.0.2:40803
(488de0351206)
I1205 11:34:05.948241 22548 master.cpp:6925] Registered agent
3f2d828b-bff8-461a-98cf-de9163b36657-S0 at slave(391)@172.17.0.2:40803
(488de0351206) with disk(reservations: [(STATIC,role1)]):1024; cpus:16;
mem:47268; ports:[31000-32000]
I1205 11:34:05.948480 22546 slave.cpp:1485] Registered with master
master@172.17.0.2:40803; given agent ID 3f2d828b-bff8-461a-98cf-de9163b36657-S0
I1205 11:34:05.948647 22552 hierarchical.cpp:603] Added agent
3f2d828b-bff8-461a-98cf-de9163b36657-S0 (488de0351206) with disk(reservations:
[(STATIC,role1)]):1024; cpus:16; mem:47268; ports:[31000-32000] (allocated: {})
I1205 11:34:05.948757 22541 task_status_update_manager.cpp:188] Resuming
sending task status updates
I1205 11:34:05.948974 22552 hierarchical.cpp:1566] Performed allocation for 1
agents in 128564ns
I1205 11:34:05.951440 22553 process.cpp:3588] Handling HTTP event for process
'master' with path: '/master/create-volumes'
I1205 11:34:05.953222 22543 http.cpp:1182] HTTP POST for /master/create-volumes
from 172.17.0.2:54640
I1205 11:34:05.954442 22543 master.cpp:3766] Authorizing principal
'test-principal' to create volumes
'[{"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"role1","type":"STATIC"}],"scalar":{"value":64.0},"type":"SCALAR"}]'
I1205 11:34:05.957434 22539 master.cpp:11404] Sending operation '' (uuid:
7468f4f8-c5ac-4f3c-9ee4-5e2a35a2ba0d) to agent
3f2d828b-bff8-461a-98cf-de9163b36657-S0 at slave(391)@172.17.0.2:40803
(488de0351206)
W1205 11:34:05.959005 22538 process.cpp:2829] Attempted to spawn already
running process version@172.17.0.2:40803
I1205 11:34:05.959853 22538 sched.cpp:232] Version: 1.8.0
I1205 11:34:05.960561 22545 sched.cpp:336] New master detected at
master@172.17.0.2:40803
I1205 11:34:05.960688 22545 sched.cpp:401] Authenticating with master
master@172.17.0.2:40803
I1205 11:34:05.960716 22545 sched.cpp:408] Using default CRAM-MD5 authenticatee
I1205 11:34:05.961017 22542 authenticatee.cpp:121] Creating new client SASL
connection
I1205 11:34:05.961308 22553 master.cpp:9699] Authenticating
scheduler-520d3cd4-9860-49ed-ac0f-20861d6d66e9@172.17.0.2:40803
I1205 11:34:05.961423 22548 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(819)@172.17.0.2:40803
I1205 11:34:05.961714 22547 authenticator.cpp:98] Creating new server SASL
connection
I1205 11:34:05.961915 22554 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I1205 11:34:05.961946 22554 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I1205 11:34:05.962057 22544 authenticator.cpp:204] Received SASL authentication
start
I1205 11:34:05.962111 22544 authenticator.cpp:326] Authentication requires more
steps
I1205 11:34:05.962213 22551 authenticatee.cpp:259] Received SASL authentication
step
I1205 11:34:05.962338 22543 authenticator.cpp:232] Received SASL authentication
step
I1205 11:34:05.962368 22543 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '488de0351206' server FQDN: '488de0351206'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I1205 11:34:05.962406 22543 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I1205 11:34:05.962447 22543 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I1205 11:34:05.962482 22543 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '488de0351206' server FQDN: '488de0351206'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
I1205 11:34:05.962497 22543 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I1205 11:34:05.962507 22543 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1205 11:34:05.962522 22543 authenticator.cpp:318] Authentication success
I1205 11:34:05.962607 22549 authenticatee.cpp:299] Authentication success
I1205 11:34:05.962695 22552 master.cpp:9731] Successfully authenticated
principal 'test-principal' at
scheduler-520d3cd4-9860-49ed-ac0f-20861d6d66e9@172.17.0.2:40803
I1205 11:34:05.962720 22541 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(819)@172.17.0.2:40803
I1205 11:34:05.962945 22539 sched.cpp:513] Successfully authenticated with
master master@172.17.0.2:40803
I1205 11:34:05.962973 22539 sched.cpp:817] Sending SUBSCRIBE call to
master@172.17.0.2:40803
I1205 11:34:05.963083 22539 sched.cpp:850] Will retry registration in
997.481606ms if necessary
I1205 11:34:05.963256 22550 master.cpp:2876] Received SUBSCRIBE call for
framework 'default' at
scheduler-520d3cd4-9860-49ed-ac0f-20861d6d66e9@172.17.0.2:40803
I1205 11:34:05.963346 22550 master.cpp:2177] Authorizing framework principal
'test-principal' to receive offers for roles '{ role1 }'
I1205 11:34:05.963752 22548 master.cpp:2957] Subscribing framework default with
checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I1205 11:34:05.965777 22548 master.cpp:9929] Adding framework
3f2d828b-bff8-461a-98cf-de9163b36657-0000 (default) at
scheduler-520d3cd4-9860-49ed-ac0f-20861d6d66e9@172.17.0.2:40803 with roles { }
suppressed
I1205 11:34:05.966181 22544 sched.cpp:744] Framework registered with
3f2d828b-bff8-461a-98cf-de9163b36657-0000
I1205 11:34:05.966231 22544 sched.cpp:758] Scheduler::registered took 22683ns
I1205 11:34:05.966593 22554 hierarchical.cpp:304] Added framework
3f2d828b-bff8-461a-98cf-de9163b36657-0000
I1205 11:34:05.967839 22554 hierarchical.cpp:1566] Performed allocation for 1
agents in 1.090412ms
I1205 11:34:05.968430 22551 master.cpp:9514] Sending offers [
3f2d828b-bff8-461a-98cf-de9163b36657-O0 ] to framework
3f2d828b-bff8-461a-98cf-de9163b36657-0000 (default) at
scheduler-520d3cd4-9860-49ed-ac0f-20861d6d66e9@172.17.0.2:40803
I1205 11:34:05.968999 22543 sched.cpp:914] Scheduler::resourceOffers took
125739ns
I1205 11:34:05.971982 22553 process.cpp:3588] Handling HTTP event for process
'master' with path: '/master/destroy-volumes'
I1205 11:34:05.973459 22540 http.cpp:1182] HTTP POST for
/master/destroy-volumes from 172.17.0.2:54642
I1205 11:34:05.974357 22540 master.cpp:3818] Authorizing principal
'test-principal' to destroy volumes
'[{"disk":{"persistence":{"id":"id1","principal":"test-princip:
al"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"role1","type":"STATIC"}],"scalar":{"value":64.0},"type":"SCALAR"}]'
I1205 11:34:05.974880 22546 slave.cpp:1505] Checkpointing SlaveInfo to
'/tmp/PersistentVolumeEndpointsTest_StaticReservation_KUwQ7i/meta/slaves/3f2d828b-bff8-461a-98cf-de9163b36657-S0/slave.info'
I1205 11:34:05.975881 22546 slave.cpp:1554] Forwarding agent update
{"operations":{},"resource_version_uuid":{"value":"Pfi8WoBdQqa6FMh+0SqEhA=="},"slave_id":{"value":"3f2d828b-bff8-461a-98cf-de9163b36657-S0"},"update_oversubscribed_resources":false}
I1205 11:34:05.976078 22540 master.cpp:11513] Removing offer
3f2d828b-bff8-461a-98cf-de9163b36657-O0
I1205 11:34:05.976299 22547 sched.cpp:940] Rescinded offer
3f2d828b-bff8-461a-98cf-de9163b36657-O0
I1205 11:34:05.976490 22547 sched.cpp:951] Scheduler::offerRescinded took
144002ns
I1205 11:34:05.976510 22552 hierarchical.cpp:1238] Recovered disk(allocated:
role1)(reservations: [(STATIC,role1)]):960; cpus(allocated: role1):16;
mem(allocated: role1):47268; ports(allocated: role1):[31000-32000];
disk(allocated: role1)(reservations: [(STATIC,role1)])[id1:path1]:64 (total:
disk(reservations: [(STATIC,role1)]):960; cpus:16; mem:47268;
ports:[31000-32000]; disk(reservations: [(STATIC,role1)])[id1:path1]:64,
allocated: {}) on agent 3f2d828b-bff8-461a-98cf-de9163b36657-S0 from framework
3f2d828b-bff8-461a-98cf-de9163b36657-0000
I1205 11:34:05.976629 22552 hierarchical.cpp:1284] Framework
3f2d828b-bff8-461a-98cf-de9163b36657-0000 filtered agent
3f2d828b-bff8-461a-98cf-de9163b36657-S0 for 5secs
I1205 11:34:05.977241 22546 slave.cpp:4208] Updated checkpointed resources from
{} to disk(reservations: [(STATIC,role1)])[id1:path1]:64
W1205 11:34:05.977272 22540 master.cpp:8049] Performing explicit reconciliation
with agent for known operation 7468f4f8-c5ac-4f3c-9ee4-5e2a35a2ba0d since it
was not present in original reconciliation message from agent
I1205 11:34:05.977330 22546 slave.cpp:7996] Updating the state of operation
with no ID (uuid: 7468f4f8-c5ac-4f3c-9ee4-5e2a35a2ba0d) for an operation API
call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I1205 11:34:05.977607 22543 master.cpp:11154] Updating the state of operation
'' (uuid: 7468f4f8-c5ac-4f3c-9ee4-5e2a35a2ba0d) for an operator API call
(latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
E1205 11:34:05.977785 22543 master.cpp:8541] Failed to find the operation ''
(uuid: 7468f4f8-c5ac-4f3c-9ee4-5e2a35a2ba0d) for an operator API call on agent
3f2d828b-bff8-461a-98cf-de9163b36657-S0
I1205 11:34:05.979140 22551 master.cpp:11404] Sending operation '' (uuid:
92effaa5-e1e3-4f85-8725-60d98a16ea3d) to agent
3f2d828b-bff8-461a-98cf-de9163b36657-S0 at slave(391)@172.17.0.2:40803
(488de0351206)
I1205 11:34:05.980224 22545 slave.cpp:4292] Deleting persistent volume 'id1' at
'/tmp/PersistentVolumeEndpointsTest_StaticReservation_KUwQ7i/volumes/roles/role1/id1'
I1205 11:34:05.980376 22549 master.cpp:6008] Processing REVIVE call for
framework 3f2d828b-bff8-461a-98cf-de9163b36657-0000 (default) at
scheduler-520d3cd4-9860-49ed-ac0f-20861d6d66e9@172.17.0.2:40803
I1205 11:34:05.980722 22552 hierarchical.cpp:703] Agent
3f2d828b-bff8-461a-98cf-de9163b36657-S0 (488de0351206) updated with total
resources disk(reservations: [(STATIC,role1)]):960; cpus:16; mem:47268;
ports:[31000-32000]; disk(reservations: [(STATIC,role1)])[id1:path1]:64
I1205 11:34:05.980906 22552 hierarchical.cpp:1387] Revived offers for roles {
role1 } of framework 3f2d828b-bff8-461a-98cf-de9163b36657-0000
I1205 11:34:05.982004 22552 hierarchical.cpp:1566] Performed allocation for 1
agents in 992415ns
I1205 11:34:05.982553 22542 master.cpp:9514] Sending offers [
3f2d828b-bff8-461a-98cf-de9163b36657-O1 ] to framework
3f2d828b-bff8-461a-98cf-de9163b36657-0000 (default) at
scheduler-520d3cd4-9860-49ed-ac0f-20861d6d66e9@172.17.0.2:40803
I1205 11:34:05.983111 22554 sched.cpp:914] Scheduler::resourceOffers took
130319ns
../../../src/tests/persistent_volume_endpoints_tests.cpp:200: Failure
Value of: Resources(offer.resources()).contains( allocatedResources(volume,
frameworkInfo.roles(0)))
Actual: true
Expected: false
I1205 11:34:05.983772 22538 sched.cpp:2008] Asked to stop the driver
I1205 11:34:05.983880 22553 sched.cpp:1184] Stopping framework
3f2d828b-bff8-461a-98cf-de9163b36657-0000
I1205 11:34:05.984138 22540 master.cpp:10231] Processing TEARDOWN call for
framework 3f2d828b-bff8-461a-98cf-de9163b36657-0000 (default) at
scheduler-520d3cd4-9860-49ed-ac0f-20861d6d66e9@172.17.0.2:40803
I1205 11:34:05.984190 22540 master.cpp:10243] Removing framework
3f2d828b-bff8-461a-98cf-de9163b36657-0000 (default) at
scheduler-520d3cd4-9860-49ed-ac0f-20861d6d66e9@172.17.0.2:40803
I1205 11:34:05.984223 22540 master.cpp:3252] Deactivating framework
3f2d828b-bff8-461a-98cf-de9163b36657-0000 (default) at
scheduler-520d3cd4-9860-49ed-ac0f-20861d6d66e9@172.17.0.2:40803
I1205 11:34:05.984350 22543 hierarchical.cpp:418] Deactivated framework
3f2d828b-bff8-461a-98cf-de9163b36657-0000
I1205 11:34:05.985057 22540 master.cpp:11513] Removing offer
3f2d828b-bff8-461a-98cf-de9163b36657-O1
I1205 11:34:05.985271 22549 hierarchical.cpp:1238] Recovered disk(allocated:
role1)(reservations: [(STATIC,role1)]):960; cpus(allocated: role1):16;
mem(allocated: role1):47268; ports(allocated: role1):[31000-32000];
disk(allocated: role1)(reservations: [(STATIC,role1)])[id1:path1]:64 (total:
disk(reservations: [(STATIC,role1)]):960; cpus:16; mem:47268;
ports:[31000-32000]; disk(reservations: [(STATIC,role1)])[id1:path1]:64,
allocated: {}) on agent 3f2d828b-bff8-461a-98cf-de9163b36657-S0 from framework
3f2d828b-bff8-461a-98cf-de9163b36657-0000
I1205 11:34:05.985641 22549 hierarchical.cpp:357] Removed framework
3f2d828b-bff8-461a-98cf-de9163b36657-0000
I1205 11:34:05.992339 22545 slave.cpp:4208] Updated checkpointed resources from
disk(reservations: [(STATIC,role1)])[id1:path1]:64 to {}
I1205 11:34:05.992427 22545 slave.cpp:7996] Updating the state of operation
with no ID (uuid: 92effaa5-e1e3-4f85-8725-60d98a16ea3d) for an operation API
call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I1205 11:34:05.992607 22545 slave.cpp:915] Agent terminating
I1205 11:34:05.992679 22553 master.cpp:11154] Updating the state of operation
'' (uuid: 92effaa5-e1e3-4f85-8725-60d98a16ea3d) for an operator API call
(latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I1205 11:34:06.170341 22554 master.cpp:1273] Agent
3f2d828b-bff8-461a-98cf-de9163b36657-S0 at slave(391)@172.17.0.2:40803
(488de0351206) disconnected
I1205 11:34:06.170404 22554 master.cpp:3289] Disconnecting agent
3f2d828b-bff8-461a-98cf-de9163b36657-S0 at slave(391)@172.17.0.2:40803
(488de0351206)
I1205 11:34:06.170560 22554 master.cpp:3308] Deactivating agent
3f2d828b-bff8-461a-98cf-de9163b36657-S0 at slave(391)@172.17.0.2:40803
(488de0351206)
I1205 11:34:06.170857 22542 hierarchical.cpp:801] Agent
3f2d828b-bff8-461a-98cf-de9163b36657-S0 deactivated
I1205 11:34:06.179515 22538 master.cpp:1115] Master terminating
I1205 11:34:06.180996 22546 hierarchical.cpp:643] Removed agent
3f2d828b-bff8-461a-98cf-de9163b36657-S0
[ FAILED ] PersistentVolumeEndpointsTest.StaticReservation (290 ms)
{noformat}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
