Uploaded image for project: 'Mesos'
  1. Mesos
  2. MESOS-9450

MasterAuthorizationTest.SlaveRemovedDropped is flaky.

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Open
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: 1.8.0
    • Fix Version/s: None
    • Component/s: test
    • Environment:

      Debian 9, autotools, libevent + SSL

      Description

      23:50:59  [ RUN      ] MasterAuthorizationTest.SlaveRemovedDropped
      23:50:59  I1203 23:50:59.123471  1137 master.cpp:414] Master 1f14ff95-e61f-4410-a724-dfec18eb52b0 (localhost) started on 127.0.0.1:33161
      23:50:59  I1203 23:50:59.123558  1137 master.cpp:417] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --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/0p45nb/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" --root_submissions="true" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/0p45nb/master" --zk_session_timeout="10secs"
      23:50:59  W1203 23:50:59.123672  1137 master.cpp:420] 
      23:50:59  **************************************************
      23:50:59  Master bound to loopback interface! Cannot communicate with remote schedulers or agents. You might want to set '--ip' flag to a routable IP address.
      23:50:59  **************************************************
      23:50:59  I1203 23:50:59.123688  1137 master.cpp:466] Master only allowing authenticated frameworks to register
      23:50:59  I1203 23:50:59.123695  1137 master.cpp:472] Master only allowing authenticated agents to register
      23:50:59  I1203 23:50:59.123702  1137 master.cpp:478] Master only allowing authenticated HTTP frameworks to register
      23:50:59  I1203 23:50:59.123708  1137 credentials.hpp:37] Loading credentials for authentication from '/tmp/0p45nb/credentials'
      23:50:59  I1203 23:50:59.123761  1137 master.cpp:522] Using default 'crammd5' authenticator
      23:50:59  I1203 23:50:59.123819  1137 http.cpp:1017] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
      23:50:59  I1203 23:50:59.123875  1137 http.cpp:1017] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
      23:50:59  I1203 23:50:59.123903  1137 http.cpp:1017] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
      23:50:59  I1203 23:50:59.123939  1137 master.cpp:603] Authorization enabled
      23:50:59  I1203 23:50:59.124068  1133 hierarchical.cpp:175] Initialized hierarchical allocator process
      23:50:59  I1203 23:50:59.124094  1138 whitelist_watcher.cpp:77] No whitelist given
      23:50:59  I1203 23:50:59.124608  1137 master.cpp:2089] Elected as the leading master!
      23:50:59  I1203 23:50:59.124625  1137 master.cpp:1644] Recovering from registrar
      23:50:59  I1203 23:50:59.124652  1136 registrar.cpp:339] Recovering registrar
      23:50:59  I1203 23:50:59.124763  1136 registrar.cpp:383] Successfully fetched the registry (0B) in 97024ns
      23:50:59  I1203 23:50:59.124807  1136 registrar.cpp:487] Applied 1 operations in 6279ns; attempting to update the registry
      23:50:59  I1203 23:50:59.124967  1136 registrar.cpp:544] Successfully updated the registry in 143104ns
      23:50:59  I1203 23:50:59.125001  1136 registrar.cpp:416] Successfully recovered registrar
      23:50:59  I1203 23:50:59.125172  1137 master.cpp:1758] Recovered 0 agents from the registry (125B); allowing 10mins for agents to reregister
      23:50:59  I1203 23:50:59.125355  1138 hierarchical.cpp:215] Skipping recovery of hierarchical allocator: nothing to recover
      23:50:59  W1203 23:50:59.126682  1117 process.cpp:2829] Attempted to spawn already running process files@127.0.0.1:33161
      23:50:59  I1203 23:50:59.126904  1117 cluster.cpp:485] Creating default 'local' authorizer
      23:50:59  I1203 23:50:59.127399  1131 slave.cpp:268] Mesos agent started on (190)@127.0.0.1:33161
      23:50:59  I1203 23:50:59.127424  1131 slave.cpp:269] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/MasterAuthorizationTest_SlaveRemovedDropped_HAw7eA/store/appc" --authenticate_http_executors="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authentication_timeout_max="1mins" --authentication_timeout_min="5secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_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/MasterAuthorizationTest_SlaveRemovedDropped_HAw7eA/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/MasterAuthorizationTest_SlaveRemovedDropped_HAw7eA/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/MasterAuthorizationTest_SlaveRemovedDropped_HAw7eA/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/MasterAuthorizationTest_SlaveRemovedDropped_HAw7eA/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/MasterAuthorizationTest_SlaveRemovedDropped_HAw7eA/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --jwt_secret_key="/tmp/MasterAuthorizationTest_SlaveRemovedDropped_HAw7eA/jwt_secret_key" --launcher="linux" --launcher_dir="/home/admin/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-debian-9/mesos/build/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="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/MasterAuthorizationTest_SlaveRemovedDropped_HAw7eA" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="false" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/MasterAuthorizationTest_SlaveRemovedDropped_Y4CBOS" --zk_session_timeout="10secs"
      23:50:59  W1203 23:50:59.127579  1131 slave.cpp:272] 
      23:50:59  **************************************************
      23:50:59  Agent bound to loopback interface! Cannot communicate with remote master(s). You might want to set '--ip' flag to a routable IP address.
      23:50:59  **************************************************
      23:50:59  I1203 23:50:59.127590  1131 credentials.hpp:86] Loading credential for authentication from '/tmp/MasterAuthorizationTest_SlaveRemovedDropped_HAw7eA/credential'
      23:50:59  I1203 23:50:59.127629  1131 slave.cpp:301] Agent using credential for: test-principal
      23:50:59  I1203 23:50:59.127647  1131 credentials.hpp:37] Loading credentials for authentication from '/tmp/MasterAuthorizationTest_SlaveRemovedDropped_HAw7eA/http_credentials'
      23:50:59  I1203 23:50:59.127701  1131 http.cpp:1017] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
      23:50:59  I1203 23:50:59.127737  1131 http.cpp:1038] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
      23:50:59  I1203 23:50:59.127779  1131 http.cpp:1017] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
      23:50:59  I1203 23:50:59.127809  1131 http.cpp:1038] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
      23:50:59  I1203 23:50:59.127840  1131 http.cpp:1017] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
      23:50:59  I1203 23:50:59.127867  1131 http.cpp:1038] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
      23:50:59  I1203 23:50:59.127928  1131 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module
      23:50:59  I1203 23:50:59.128084  1131 slave.cpp:616] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
      23:50:59  I1203 23:50:59.128134  1131 slave.cpp:624] Agent attributes: [  ]
      23:50:59  I1203 23:50:59.128142  1131 slave.cpp:633] Agent hostname: localhost
      23:50:59  I1203 23:50:59.128199  1132 task_status_update_manager.cpp:181] Pausing sending task status updates
      23:50:59  I1203 23:50:59.128334  1131 state.cpp:66] Recovering state from '/tmp/MasterAuthorizationTest_SlaveRemovedDropped_Y4CBOS/meta'
      23:50:59  I1203 23:50:59.128453  1136 slave.cpp:6914] Finished recovering checkpointed state from '/tmp/MasterAuthorizationTest_SlaveRemovedDropped_Y4CBOS/meta', beginning agent recovery
      23:50:59  I1203 23:50:59.128532  1132 task_status_update_manager.cpp:207] Recovering task status update manager
      23:50:59  W1203 23:50:59.128793  1117 sched.cpp:1714] 
      23:50:59  **************************************************
      23:50:59  Scheduler driver bound to loopback interface! Cannot communicate with remote master(s). You might want to set 'LIBPROCESS_IP' environment variable to use a routable IP address.
      23:50:59  **************************************************
      23:50:59  I1203 23:50:59.128831  1138 composing.cpp:339] Finished recovering all containerizers
      23:50:59  I1203 23:50:59.128896  1134 slave.cpp:7143] Recovering executors
      23:50:59  I1203 23:50:59.128999  1134 slave.cpp:7296] Finished recovery
      23:50:59  W1203 23:50:59.128830  1117 process.cpp:2829] Attempted to spawn already running process version@127.0.0.1:33161
      23:50:59  I1203 23:50:59.129387  1135 task_status_update_manager.cpp:181] Pausing sending task status updates
      23:50:59  I1203 23:50:59.129427  1134 slave.cpp:1259] New master detected at master@127.0.0.1:33161
      23:50:59  I1203 23:50:59.129547  1134 slave.cpp:1324] Detecting new master
      23:50:59  I1203 23:50:59.129853  1117 sched.cpp:232] Version: 1.8.0
      23:50:59  I1203 23:50:59.130002  1134 sched.cpp:336] New master detected at master@127.0.0.1:33161
      23:50:59  I1203 23:50:59.130035  1134 sched.cpp:401] Authenticating with master master@127.0.0.1:33161
      23:50:59  I1203 23:50:59.130043  1134 sched.cpp:408] Using default CRAM-MD5 authenticatee
      23:50:59  I1203 23:50:59.130195  1136 authenticatee.cpp:121] Creating new client SASL connection
      23:50:59  I1203 23:50:59.130283  1136 master.cpp:9649] Authenticating scheduler-5b888f8c-bf1b-4028-ba88-a095bd795459@127.0.0.1:33161
      23:50:59  I1203 23:50:59.130326  1137 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(411)@127.0.0.1:33161
      23:50:59  I1203 23:50:59.130451  1137 authenticator.cpp:98] Creating new server SASL connection
      23:50:59  I1203 23:50:59.130590  1133 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
      23:50:59  I1203 23:50:59.130611  1133 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
      23:50:59  I1203 23:50:59.130645  1131 authenticator.cpp:204] Received SASL authentication start
      23:50:59  I1203 23:50:59.130674  1131 authenticator.cpp:326] Authentication requires more steps
      23:50:59  I1203 23:50:59.130722  1133 authenticatee.cpp:259] Received SASL authentication step
      23:50:59  I1203 23:50:59.130771  1134 authenticator.cpp:232] Received SASL authentication step
      23:50:59  I1203 23:50:59.130786  1134 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-142' server FQDN: 'ip-172-16-10-142' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
      23:50:59  I1203 23:50:59.130807  1134 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
      23:50:59  I1203 23:50:59.130817  1134 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
      23:50:59  I1203 23:50:59.130825  1134 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-142' server FQDN: 'ip-172-16-10-142' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
      23:50:59  I1203 23:50:59.130831  1134 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
      23:50:59  I1203 23:50:59.130848  1134 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
      23:50:59  I1203 23:50:59.130861  1134 authenticator.cpp:318] Authentication success
      23:50:59  I1203 23:50:59.130895  1138 master.cpp:9681] Successfully authenticated principal 'test-principal' at scheduler-5b888f8c-bf1b-4028-ba88-a095bd795459@127.0.0.1:33161
      23:50:59  I1203 23:50:59.130961  1134 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(411)@127.0.0.1:33161
      23:50:59  I1203 23:50:59.133492  1133 authenticatee.cpp:299] Authentication success
      23:50:59  I1203 23:50:59.133700  1133 sched.cpp:513] Successfully authenticated with master master@127.0.0.1:33161
      23:50:59  I1203 23:50:59.133756  1138 slave.cpp:1351] Authenticating with master master@127.0.0.1:33161
      23:50:59  I1203 23:50:59.133787  1138 slave.cpp:1360] Using default CRAM-MD5 authenticatee
      23:50:59  I1203 23:50:59.133772  1133 sched.cpp:817] Sending SUBSCRIBE call to master@127.0.0.1:33161
      23:50:59  I1203 23:50:59.133908  1133 sched.cpp:850] Will retry registration in 525.348239ms if necessary
      23:50:59  I1203 23:50:59.133846  1138 authenticatee.cpp:121] Creating new client SASL connection
      23:50:59  I1203 23:50:59.133991  1137 master.cpp:2860] Received SUBSCRIBE call for framework 'default' at scheduler-5b888f8c-bf1b-4028-ba88-a095bd795459@127.0.0.1:33161
      23:50:59  I1203 23:50:59.134230  1137 master.cpp:2161] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
      23:50:59  I1203 23:50:59.134366  1137 master.cpp:9649] Authenticating slave(190)@127.0.0.1:33161
      23:50:59  I1203 23:50:59.134440  1132 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(412)@127.0.0.1:33161
      23:50:59  I1203 23:50:59.134565  1132 authenticator.cpp:98] Creating new server SASL connection
      23:50:59  I1203 23:50:59.134413  1137 master.cpp:2941] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT, PARTITION_AWARE ]
      23:50:59  I1203 23:50:59.134711  1132 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
      23:50:59  I1203 23:50:59.134816  1132 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
      23:50:59  I1203 23:50:59.134907  1132 authenticator.cpp:204] Received SASL authentication start
      23:50:59  I1203 23:50:59.134990  1132 authenticator.cpp:326] Authentication requires more steps
      23:50:59  I1203 23:50:59.135082  1132 authenticatee.cpp:259] Received SASL authentication step
      23:50:59  I1203 23:50:59.135176  1132 authenticator.cpp:232] Received SASL authentication step
      23:50:59  I1203 23:50:59.135254  1132 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-142' server FQDN: 'ip-172-16-10-142' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
      23:50:59  I1203 23:50:59.135318  1132 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
      23:50:59  I1203 23:50:59.135380  1132 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
      23:50:59  I1203 23:50:59.135457  1132 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-142' server FQDN: 'ip-172-16-10-142' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
      23:50:59  I1203 23:50:59.135519  1132 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
      23:50:59  I1203 23:50:59.135578  1132 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
      23:50:59  I1203 23:50:59.135644  1132 authenticator.cpp:318] Authentication success
      23:50:59  I1203 23:50:59.135723  1131 authenticatee.cpp:299] Authentication success
      23:50:59  I1203 23:50:59.135804  1138 slave.cpp:1451] Successfully authenticated with master master@127.0.0.1:33161
      23:50:59  I1203 23:50:59.135816  1135 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(412)@127.0.0.1:33161
      23:50:59  I1203 23:50:59.135885  1138 slave.cpp:1882] Will retry registration in 1.72993ms if necessary
      23:50:59  I1203 23:50:59.136350  1137 master.cpp:9879] Adding framework 1f14ff95-e61f-4410-a724-dfec18eb52b0-0000 (default) at scheduler-5b888f8c-bf1b-4028-ba88-a095bd795459@127.0.0.1:33161 with roles {  } suppressed
      23:50:59  I1203 23:50:59.136554  1132 sched.cpp:744] Framework registered with 1f14ff95-e61f-4410-a724-dfec18eb52b0-0000
      23:50:59  I1203 23:50:59.136646  1135 hierarchical.cpp:304] Added framework 1f14ff95-e61f-4410-a724-dfec18eb52b0-0000
      23:50:59  I1203 23:50:59.136693  1135 hierarchical.cpp:1566] Performed allocation for 0 agents in 6815ns
      23:50:59  I1203 23:50:59.136698  1132 sched.cpp:758] Scheduler::registered took 41510ns
      23:50:59  I1203 23:50:59.136837  1137 master.cpp:9681] Successfully authenticated principal 'test-principal' at slave(190)@127.0.0.1:33161
      23:50:59  I1203 23:50:59.136957  1137 master.cpp:6600] Received register agent message from slave(190)@127.0.0.1:33161 (localhost)
      23:50:59  I1203 23:50:59.137078  1137 master.cpp:3930] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal'
      23:50:59  I1203 23:50:59.137264  1136 master.cpp:6667] Authorized registration of agent at slave(190)@127.0.0.1:33161 (localhost)
      23:50:59  I1203 23:50:59.137300  1136 master.cpp:6782] Registering agent at slave(190)@127.0.0.1:33161 (localhost) with id 1f14ff95-e61f-4410-a724-dfec18eb52b0-S0
      23:50:59  I1203 23:50:59.137399  1136 registrar.cpp:487] Applied 1 operations in 29046ns; attempting to update the registry
      23:50:59  I1203 23:50:59.137612  1136 registrar.cpp:544] Successfully updated the registry in 188928ns
      23:50:59  I1203 23:50:59.137661  1136 master.cpp:6830] Admitted agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S0 at slave(190)@127.0.0.1:33161 (localhost)
      23:50:59  I1203 23:50:59.137811  1138 hierarchical.cpp:603] Added agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S0 (localhost) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
      23:50:59  I1203 23:50:59.137928  1138 hierarchical.cpp:1566] Performed allocation for 1 agents in 66190ns
      23:50:59  I1203 23:50:59.138115  1135 slave.cpp:1882] Will retry registration in 8.146728ms if necessary
      23:50:59  I1203 23:50:59.138185  1136 master.cpp:6875] Registered agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S0 at slave(190)@127.0.0.1:33161 (localhost) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
      23:50:59  I1203 23:50:59.138203  1131 slave.cpp:1484] Registered with master master@127.0.0.1:33161; given agent ID 1f14ff95-e61f-4410-a724-dfec18eb52b0-S0
      23:50:59  I1203 23:50:59.138299  1136 master.cpp:9464] Sending offers [ 1f14ff95-e61f-4410-a724-dfec18eb52b0-O0 ] to framework 1f14ff95-e61f-4410-a724-dfec18eb52b0-0000 (default) at scheduler-5b888f8c-bf1b-4028-ba88-a095bd795459@127.0.0.1:33161
      23:50:59  I1203 23:50:59.138345  1138 task_status_update_manager.cpp:188] Resuming sending task status updates
      23:50:59  I1203 23:50:59.138355  1131 slave.cpp:1504] Checkpointing SlaveInfo to '/tmp/MasterAuthorizationTest_SlaveRemovedDropped_Y4CBOS/meta/slaves/1f14ff95-e61f-4410-a724-dfec18eb52b0-S0/slave.info'
      23:50:59  I1203 23:50:59.138448  1138 sched.cpp:914] Scheduler::resourceOffers took 34264ns
      23:50:59  I1203 23:50:59.138561  1136 master.cpp:6600] Received register agent message from slave(190)@127.0.0.1:33161 (localhost)
      23:50:59  I1203 23:50:59.138612  1131 slave.cpp:1553] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"s4oKlvW0SqGIwtabOQA/Kw=="},"slave_id":{"value":"1f14ff95-e61f-4410-a724-dfec18eb52b0-S0"},"update_oversubscribed_resources":false}
      23:50:59  I1203 23:50:59.138622  1136 master.cpp:3930] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal'
      23:50:59  I1203 23:50:59.139066  1117 slave.cpp:955] Unregistering and shutting down
      23:50:59  I1203 23:50:59.139091  1117 slave.cpp:914] Agent terminating
      23:50:59  I1203 23:50:59.139104  1136 master.cpp:7934] Ignoring update on agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S0 at slave(190)@127.0.0.1:33161 (localhost) as it reports no changes
      23:50:59  I1203 23:50:59.139221  1136 master.cpp:11463] Removing offer 1f14ff95-e61f-4410-a724-dfec18eb52b0-O0
      23:50:59  I1203 23:50:59.139493  1136 master.cpp:4451] Processing ACCEPT call for offers: [ 1f14ff95-e61f-4410-a724-dfec18eb52b0-O0 ] on agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S0 at slave(190)@127.0.0.1:33161 (localhost) for framework 1f14ff95-e61f-4410-a724-dfec18eb52b0-0000 (default) at scheduler-5b888f8c-bf1b-4028-ba88-a095bd795459@127.0.0.1:33161
      23:50:59  I1203 23:50:59.139535  1136 master.cpp:3547] Authorizing framework principal 'test-principal' to launch task 3e709379-4bcf-43ac-b512-14144fcedc94
      23:50:59  ../../src/tests/master_authorization_tests.cpp:730: Failure
      23:50:59  Mock function called more times than expected - returning default value.
      23:50:59      Function call: authorized(@0x7f70b98d7d20 48-byte object <90-CC B1-C7 70-7F 00-00 00-00 00-00 00-00 00-00 07-00 00-00 00-00 00-00 F0-26 09-98 70-7F 00-00 A0-BE 0C-98 70-7F 00-00 02-00 00-00 E2-84 5A-3B>)
      23:50:59            Returns: Abandoned
      23:50:59           Expected: to be called once
      23:50:59             Actual: called twice - over-saturated and active
      23:50:59  I1203 23:50:59.141641  1136 master.cpp:10568] Removing agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S0 at slave(190)@127.0.0.1:33161 (localhost): the agent unregistered
      23:50:59  I1203 23:50:59.141929  1136 registrar.cpp:487] Applied 1 operations in 14037ns; attempting to update the registry
      23:50:59  I1203 23:50:59.145511  1135 registrar.cpp:544] Successfully updated the registry in 3.556096ms
      23:50:59  I1203 23:50:59.145565  1134 master.cpp:10610] Removed agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S0 at slave(190)@127.0.0.1:33161 (localhost): the agent unregistered
      23:50:59  I1203 23:50:59.145629  1134 master.cpp:2006] Notifying framework 1f14ff95-e61f-4410-a724-dfec18eb52b0-0000 (default) at scheduler-5b888f8c-bf1b-4028-ba88-a095bd795459@127.0.0.1:33161 of lost agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S0 (localhost)
      23:50:59  I1203 23:50:59.145730  1134 hierarchical.cpp:643] Removed agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S0
      23:50:59  I1203 23:50:59.145773  1134 sched.cpp:1084] Lost agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S0
      23:50:59  I1203 23:50:59.145884  1134 sched.cpp:1095] Scheduler::slaveLost took 12093ns
      23:50:59  I1203 23:50:59.148435  1133 master.cpp:6667] Authorized registration of agent at slave(190)@127.0.0.1:33161 (localhost)
      23:50:59  I1203 23:50:59.148476  1133 master.cpp:6782] Registering agent at slave(190)@127.0.0.1:33161 (localhost) with id 1f14ff95-e61f-4410-a724-dfec18eb52b0-S1
      23:50:59  I1203 23:50:59.148671  1133 registrar.cpp:487] Applied 1 operations in 28758ns; attempting to update the registry
      23:50:59  I1203 23:50:59.148871  1133 registrar.cpp:544] Successfully updated the registry in 173056ns
      23:50:59  I1203 23:50:59.148982  1133 master.cpp:6830] Admitted agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S1 at slave(190)@127.0.0.1:33161 (localhost)
      23:50:59  I1203 23:50:59.149173  1138 hierarchical.cpp:603] Added agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S1 (localhost) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
      23:50:59  I1203 23:50:59.149292  1138 hierarchical.cpp:1566] Performed allocation for 1 agents in 68046ns
      23:50:59  I1203 23:50:59.149422  1133 master.cpp:6875] Registered agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S1 at slave(190)@127.0.0.1:33161 (localhost) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
      23:50:59  I1203 23:50:59.149507  1133 master.cpp:1275] Agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S1 at slave(190)@127.0.0.1:33161 (localhost) disconnected
      23:50:59  I1203 23:50:59.149590  1133 master.cpp:3273] Disconnecting agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S1 at slave(190)@127.0.0.1:33161 (localhost)
      23:50:59  I1203 23:50:59.149610  1133 master.cpp:3292] Deactivating agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S1 at slave(190)@127.0.0.1:33161 (localhost)
      23:50:59  I1203 23:50:59.149828  1131 hierarchical.cpp:801] Agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S1 deactivated
      23:50:59  W1203 23:50:59.149855  1133 master.cpp:9319] Master returning resources offered because agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S1 at slave(190)@127.0.0.1:33161 (localhost) is disconnected
      23:50:59  I1203 23:50:59.150014  1136 hierarchical.cpp:1238] Recovered cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: {}) on agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S1 from framework 1f14ff95-e61f-4410-a724-dfec18eb52b0-0000
      23:51:00  I1203 23:51:00.124913  1136 hierarchical.cpp:1566] Performed allocation for 1 agents in 31120ns
      23:51:01  I1203 23:51:01.125872  1134 hierarchical.cpp:1566] Performed allocation for 1 agents in 29988ns
      23:51:02  I1203 23:51:02.127084  1135 hierarchical.cpp:1566] Performed allocation for 1 agents in 30038ns
      23:51:03  I1203 23:51:03.127851  1132 hierarchical.cpp:1566] Performed allocation for 1 agents in 30798ns
      23:51:04  I1203 23:51:04.128324  1136 hierarchical.cpp:1566] Performed allocation for 1 agents in 32370ns
      23:51:05  I1203 23:51:05.129272  1137 hierarchical.cpp:1566] Performed allocation for 1 agents in 29156ns
      23:51:06  I1203 23:51:06.130210  1135 hierarchical.cpp:1566] Performed allocation for 1 agents in 31558ns
      23:51:07  I1203 23:51:07.131202  1134 hierarchical.cpp:1566] Performed allocation for 1 agents in 31200ns
      23:51:08  I1203 23:51:08.132498  1135 hierarchical.cpp:1566] Performed allocation for 1 agents in 32824ns
      23:51:09  I1203 23:51:09.133617  1133 hierarchical.cpp:1566] Performed allocation for 1 agents in 31312ns
      23:51:10  I1203 23:51:10.134618  1135 hierarchical.cpp:1566] Performed allocation for 1 agents in 32366ns
      23:51:11  I1203 23:51:11.135648  1133 hierarchical.cpp:1566] Performed allocation for 1 agents in 31148ns
      23:51:12  I1203 23:51:12.136601  1132 hierarchical.cpp:1566] Performed allocation for 1 agents in 31649ns
      23:51:13  I1203 23:51:13.137598  1134 hierarchical.cpp:1566] Performed allocation for 1 agents in 30865ns
      23:51:14  I1203 23:51:14.138133  1133 hierarchical.cpp:1566] Performed allocation for 1 agents in 30841ns
      23:51:14  ../../src/tests/master_authorization_tests.cpp:761: Failure
      23:51:14  Failed to wait 15secs for status
      23:51:14  I../../src/tests/master_authorization_tests.cpp:751: Failure
      23:51:14  Actual function call count doesn't match EXPECT_CALL(sched, statusUpdate(&driver, _))...
      23:51:14           Expected: to be called once
      23:51:14             Actual: never called - unsatisfied and active
      23:51:14  1203 23:51:14.149539  1131 master.cpp:1390] Framework 1f14ff95-e61f-4410-a724-dfec18eb52b0-0000 (default) at scheduler-5b888f8c-bf1b-4028-ba88-a095bd795459@127.0.0.1:33161 disconnected
      23:51:14  I1203 23:51:14.149920  1131 master.cpp:3236] Deactivating framework 1f14ff95-e61f-4410-a724-dfec18eb52b0-0000 (default) at scheduler-5b888f8c-bf1b-4028-ba88-a095bd795459@127.0.0.1:33161
      23:51:14  I1203 23:51:14.149957  1131 master.cpp:3213] Disconnecting framework 1f14ff95-e61f-4410-a724-dfec18eb52b0-0000 (default) at scheduler-5b888f8c-bf1b-4028-ba88-a095bd795459@127.0.0.1:33161
      23:51:14  I1203 23:51:14.149972  1131 master.cpp:1405] Giving framework 1f14ff95-e61f-4410-a724-dfec18eb52b0-0000 (default) at scheduler-5b888f8c-bf1b-4028-ba88-a095bd795459@127.0.0.1:33161 0ns to failover
      23:51:14  I1203 23:51:14.150179  1131 master.cpp:1117] Master terminating
      23:51:14  I1203 23:51:14.150317  1133 hierarchical.cpp:418] Deactivated framework 1f14ff95-e61f-4410-a724-dfec18eb52b0-0000
      23:51:14  I1203 23:51:14.151087  1133 hierarchical.cpp:643] Removed agent 1f14ff95-e61f-4410-a724-dfec18eb52b0-S1
      23:51:14  [  FAILED  ] MasterAuthorizationTest.SlaveRemovedDropped (15029 ms)
      

        Attachments

          Activity

            People

            • Assignee:
              Unassigned
              Reporter:
              tillt Till Toenshoff
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated: