You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@mesos.apache.org by "Greg Mann (JIRA)" <ji...@apache.org> on 2019/01/16 18:28:00 UTC

[jira] [Assigned] (MESOS-9458) PersistentVolumeEndpointsTest.StaticReservation is flaky

     [ https://issues.apache.org/jira/browse/MESOS-9458?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Greg Mann reassigned MESOS-9458:
--------------------------------

    Assignee: Greg Mann  (was: Meng Zhu)

> PersistentVolumeEndpointsTest.StaticReservation is flaky
> --------------------------------------------------------
>
>                 Key: MESOS-9458
>                 URL: https://issues.apache.org/jira/browse/MESOS-9458
>             Project: Mesos
>          Issue Type: Bug
>            Reporter: Vinod Kone
>            Assignee: Greg Mann
>            Priority: Major
>              Labels: flaky-test, foundations, 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)