[ https://issues.apache.org/jira/browse/MESOS-9458?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16713238#comment-16713238 ]
Meng Zhu commented on MESOS-9458: --------------------------------- Caused by MESOS-9460 > 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 > Assignee: Meng Zhu > Priority: Major > Labels: flaky-test, mesosphere > > 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)