[ RUN ] RoleTest.RolesEndpointContainsConsumedQuota
I0710 07:05:42.670790 9995 cluster.cpp:176] Creating default 'local' authorizer
I0710 07:05:42.672238 9999 master.cpp:440] Master 8db40cec-43ef-41a1-89a4-4f7b877d8f13 (ip-172-16-10-69.ec2.internal) started on 172.16.10.69:37082
I0710 07:05:42.672256 9999 master.cpp:443] 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/1d0m6o/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_operator_event_stream_subscribers="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/1d0m6o/master" --zk_session_timeout="10secs"
I0710 07:05:42.672351 9999 master.cpp:492] Master only allowing authenticated frameworks to register
I0710 07:05:42.672356 9999 master.cpp:498] Master only allowing authenticated agents to register
I0710 07:05:42.672360 9999 master.cpp:504] Master only allowing authenticated HTTP frameworks to register
I0710 07:05:42.672364 9999 credentials.hpp:37] Loading credentials for authentication from '/tmp/1d0m6o/credentials'
I0710 07:05:42.672430 9999 master.cpp:548] Using default 'crammd5' authenticator
I0710 07:05:42.672466 9999 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0710 07:05:42.672508 9999 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0710 07:05:42.672538 9999 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0710 07:05:42.672569 9999 master.cpp:629] Authorization enabled
I0710 07:05:42.672658 10001 hierarchical.cpp:241] Initialized hierarchical allocator process
I0710 07:05:42.672685 10001 whitelist_watcher.cpp:77] No whitelist given
I0710 07:05:42.673316 10001 master.cpp:2150] Elected as the leading master!
I0710 07:05:42.673331 10001 master.cpp:1664] Recovering from registrar
I0710 07:05:42.673616 10001 registrar.cpp:339] Recovering registrar
I0710 07:05:42.673874 10001 registrar.cpp:383] Successfully fetched the registry (0B) in 239104ns
I0710 07:05:42.673923 10001 registrar.cpp:487] Applied 1 operations in 7745ns; attempting to update the registry
I0710 07:05:42.674052 9999 registrar.cpp:544] Successfully updated the registry in 108032ns
I0710 07:05:42.674082 9999 registrar.cpp:416] Successfully recovered registrar
I0710 07:05:42.674152 9999 master.cpp:1799] Recovered 0 agents from the registry (180B); allowing 10mins for agents to reregister
I0710 07:05:42.674185 9996 hierarchical.cpp:280] Skipping recovery of hierarchical allocator: nothing to recover
W0710 07:05:42.676100 9995 process.cpp:2877] Attempted to spawn already running process files@172.16.10.69:37082
I0710 07:05:42.676537 9995 containerizer.cpp:314] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
I0710 07:05:42.678514 9995 linux_launcher.cpp:144] Using /cgroup/freezer as the freezer hierarchy for the Linux launcher
I0710 07:05:42.678980 9995 provisioner.cpp:298] Using default backend 'copy'
I0710 07:05:42.680043 9995 cluster.cpp:510] Creating default 'local' authorizer
I0710 07:05:42.680832 9998 slave.cpp:265] Mesos agent started on (522)@172.16.10.69:37082
I0710 07:05:42.680850 9998 slave.cpp:266] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/1d0m6o/qvvVks/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/1d0m6o/qvvVks/credential" --default_role="*" --disallow_sharing_agent_ipc_namespace="false" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_ignore_runtime="false" --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/1d0m6o/qvvVks/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/1d0m6o/qvvVks/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/1d0m6o/qvvVks/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/1d0m6o/qvvVks/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --jwt_secret_key="/tmp/1d0m6o/qvvVks/jwt_secret_key" --launcher="linux" --launcher_dir="/home/centos/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-centos-6/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --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(role):1;mem(role):10;disk:0;ports:[]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/RoleTest_RolesEndpointContainsConsumedQuota_1IIJA6" --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/RoleTest_RolesEndpointContainsConsumedQuota_xr6xQK" --zk_session_timeout="10secs"
I0710 07:05:42.681233 9998 credentials.hpp:86] Loading credential for authentication from '/tmp/1d0m6o/qvvVks/credential'
I0710 07:05:42.681301 9998 slave.cpp:298] Agent using credential for: test-principal
I0710 07:05:42.681313 9998 credentials.hpp:37] Loading credentials for authentication from '/tmp/1d0m6o/qvvVks/http_credentials'
I0710 07:05:42.681396 9998 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
I0710 07:05:42.681429 9998 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
I0710 07:05:42.681473 9998 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0710 07:05:42.681493 9998 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
I0710 07:05:42.681519 9998 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
I0710 07:05:42.681535 9998 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
W0710 07:05:42.681565 9995 process.cpp:2877] Attempted to spawn already running process version@172.16.10.69:37082
I0710 07:05:42.681998 9998 disk_profile_adaptor.cpp:78] Creating default disk profile adaptor module
I0710 07:05:42.682571 9998 slave.cpp:613] Agent resources: [{"name":"cpus","reservations":[{"role":"role","type":"STATIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"name":"mem","reservations":[{"role":"role","type":"STATIC"}],"scalar":{"value":10.0},"type":"SCALAR"}]
I0710 07:05:42.682636 9998 slave.cpp:621] Agent attributes: [ ]
I0710 07:05:42.682643 9998 slave.cpp:630] Agent hostname: ip-172-16-10-69.ec2.internal
I0710 07:05:42.682718 9996 task_status_update_manager.cpp:181] Pausing sending task status updates
I0710 07:05:42.682737 9996 status_update_manager_process.hpp:379] Pausing operation status update manager
I0710 07:05:42.682947 9998 state.cpp:67] Recovering state from '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_xr6xQK/meta'
I0710 07:05:42.683017 9998 slave.cpp:7246] Finished recovering checkpointed state from '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_xr6xQK/meta', beginning agent recovery
I0710 07:05:42.683105 9998 task_status_update_manager.cpp:207] Recovering task status update manager
I0710 07:05:42.683320 10002 containerizer.cpp:796] Recovering Mesos containers
I0710 07:05:42.683378 10002 linux_launcher.cpp:286] Recovering Linux launcher
I0710 07:05:42.683485 10002 containerizer.cpp:1122] Recovering isolators
I0710 07:05:42.683931 10000 containerizer.cpp:1161] Recovering provisioner
I0710 07:05:42.684257 10001 provisioner.cpp:498] Provisioner recovery complete
I0710 07:05:42.684689 9997 composing.cpp:339] Finished recovering all containerizers
I0710 07:05:42.684762 9997 slave.cpp:7708] Recovering executors
I0710 07:05:42.684785 9997 slave.cpp:7861] Finished recovery
I0710 07:05:42.685237 9996 status_update_manager_process.hpp:379] Pausing operation status update manager
I0710 07:05:42.685223 10003 task_status_update_manager.cpp:181] Pausing sending task status updates
I0710 07:05:42.685498 9995 sched.cpp:239] Version: 1.9.0
I0710 07:05:42.685214 9997 slave.cpp:1258] New master detected at master@172.16.10.69:37082
I0710 07:05:42.685556 9997 slave.cpp:1323] Detecting new master
I0710 07:05:42.685786 9997 sched.cpp:343] New master detected at master@172.16.10.69:37082
I0710 07:05:42.686059 9997 sched.cpp:408] Authenticating with master master@172.16.10.69:37082
I0710 07:05:42.686069 9997 sched.cpp:415] Using default CRAM-MD5 authenticatee
I0710 07:05:42.686162 9997 authenticatee.cpp:121] Creating new client SASL connection
I0710 07:05:42.686285 9999 master.cpp:10380] Authenticating scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082
I0710 07:05:42.686347 9999 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1050)@172.16.10.69:37082
I0710 07:05:42.686412 9999 authenticator.cpp:98] Creating new server SASL connection
I0710 07:05:42.686487 9999 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0710 07:05:42.686499 9999 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0710 07:05:42.686535 9999 authenticator.cpp:204] Received SASL authentication start
I0710 07:05:42.686586 9999 authenticator.cpp:326] Authentication requires more steps
I0710 07:05:42.686622 9999 authenticatee.cpp:259] Received SASL authentication step
I0710 07:05:42.686669 9999 authenticator.cpp:232] Received SASL authentication step
I0710 07:05:42.686686 9999 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-69' server FQDN: 'ip-172-16-10-69' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0710 07:05:42.686715 9999 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0710 07:05:42.686728 9999 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0710 07:05:42.686738 9999 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-69' server FQDN: 'ip-172-16-10-69' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0710 07:05:42.686743 9999 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0710 07:05:42.686749 9999 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0710 07:05:42.686763 9999 authenticator.cpp:318] Authentication success
I0710 07:05:42.686810 9999 authenticatee.cpp:299] Authentication success
I0710 07:05:42.686854 9999 master.cpp:10412] Successfully authenticated principal 'test-principal' at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082
I0710 07:05:42.686887 10000 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1050)@172.16.10.69:37082
I0710 07:05:42.687379 9999 sched.cpp:520] Successfully authenticated with master master@172.16.10.69:37082
I0710 07:05:42.687400 9999 sched.cpp:835] Sending SUBSCRIBE call to master@172.16.10.69:37082
I0710 07:05:42.687448 9999 sched.cpp:870] Will retry registration in 667.029736ms if necessary
I0710 07:05:42.687536 10001 master.cpp:2890] Received SUBSCRIBE call for framework 'default' at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082
I0710 07:05:42.687556 10001 master.cpp:2222] Authorizing framework principal 'test-principal' to receive offers for roles '{ role }'
I0710 07:05:42.687672 9998 master.cpp:2977] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0710 07:05:42.688201 9998 master.cpp:10610] Adding framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082 with roles { } suppressed
I0710 07:05:42.688334 10000 sched.cpp:751] Framework registered with 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.688364 10000 sched.cpp:770] Scheduler::registered took 14639ns
I0710 07:05:42.689081 9998 hierarchical.cpp:368] Added framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.689308 9998 hierarchical.cpp:1508] Performed allocation for 0 agents in 29346ns
I0710 07:05:42.693774 9997 slave.cpp:1350] Authenticating with master master@172.16.10.69:37082
I0710 07:05:42.693804 9997 slave.cpp:1359] Using default CRAM-MD5 authenticatee
I0710 07:05:42.693876 9997 authenticatee.cpp:121] Creating new client SASL connection
I0710 07:05:42.693958 9997 master.cpp:10380] Authenticating slave(522)@172.16.10.69:37082
I0710 07:05:42.693998 9997 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1051)@172.16.10.69:37082
I0710 07:05:42.694056 9997 authenticator.cpp:98] Creating new server SASL connection
I0710 07:05:42.694115 9997 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0710 07:05:42.694125 9997 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0710 07:05:42.694160 9999 authenticator.cpp:204] Received SASL authentication start
I0710 07:05:42.694198 9999 authenticator.cpp:326] Authentication requires more steps
I0710 07:05:42.694236 9999 authenticatee.cpp:259] Received SASL authentication step
I0710 07:05:42.694277 9999 authenticator.cpp:232] Received SASL authentication step
I0710 07:05:42.694290 9999 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-69' server FQDN: 'ip-172-16-10-69' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0710 07:05:42.694296 9999 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0710 07:05:42.694304 9999 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0710 07:05:42.694312 9999 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-69' server FQDN: 'ip-172-16-10-69' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0710 07:05:42.694319 9999 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0710 07:05:42.694336 9999 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0710 07:05:42.694345 9999 authenticator.cpp:318] Authentication success
I0710 07:05:42.694392 10001 authenticatee.cpp:299] Authentication success
I0710 07:05:42.694452 9999 master.cpp:10412] Successfully authenticated principal 'test-principal' at slave(522)@172.16.10.69:37082
I0710 07:05:42.694469 10001 slave.cpp:1450] Successfully authenticated with master master@172.16.10.69:37082
I0710 07:05:42.694512 10003 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1051)@172.16.10.69:37082
I0710 07:05:42.694573 10001 slave.cpp:1900] Will retry registration in 15.73611ms if necessary
I0710 07:05:42.694640 10001 master.cpp:6900] Received register agent message from slave(522)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.694720 10001 master.cpp:4099] Authorizing agent providing resources 'cpus(reservations: [(STATIC,role)]):1; mem(reservations: [(STATIC,role)]):10' with principal 'test-principal'
I0710 07:05:42.694792 10001 master.cpp:3721] Authorizing principal 'test-principal' to reserve resources 'cpus(reservations: [(STATIC,role)]):1; mem(reservations: [(STATIC,role)]):10'
I0710 07:05:42.694949 10001 master.cpp:6967] Authorized registration of agent at slave(522)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.694988 10001 master.cpp:7082] Registering agent at slave(522)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal) with id 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0
I0710 07:05:42.695119 10001 registrar.cpp:487] Applied 1 operations in 52120ns; attempting to update the registry
I0710 07:05:42.695276 10001 registrar.cpp:544] Successfully updated the registry in 137216ns
I0710 07:05:42.695327 10001 master.cpp:7130] Admitted agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0 at slave(522)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.695451 10001 master.cpp:7175] Registered agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0 at slave(522)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal) with cpus(reservations: [(STATIC,role)]):1; mem(reservations: [(STATIC,role)]):10
I0710 07:05:42.695500 10000 hierarchical.cpp:617] Added agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0 (ip-172-16-10-69.ec2.internal) with cpus(reservations: [(STATIC,role)]):1; mem(reservations: [(STATIC,role)]):10 (allocated: {})
I0710 07:05:42.695525 10001 slave.cpp:1483] Registered with master master@172.16.10.69:37082; given agent ID 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0
I0710 07:05:42.695639 10000 hierarchical.cpp:1508] Performed allocation for 1 agents in 92565ns
I0710 07:05:42.695673 10000 task_status_update_manager.cpp:188] Resuming sending task status updates
I0710 07:05:42.695745 10001 slave.cpp:1518] Checkpointing SlaveInfo to '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_xr6xQK/meta/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0/slave.info'
I0710 07:05:42.695773 10000 master.cpp:10195] Sending offers [ 8db40cec-43ef-41a1-89a4-4f7b877d8f13-O0 ] to framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082
I0710 07:05:42.695832 10000 status_update_manager_process.hpp:385] Resuming operation status update manager
I0710 07:05:42.696385 10001 slave.cpp:1570] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"RXSv7a6tQBuTqO8uJ7NIJw=="},"slave_id":{"value":"8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0"},"update_oversubscribed_resources":false}
I0710 07:05:42.696590 10001 master.cpp:8261] Ignoring update on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0 at slave(522)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal) as it reports no changes
I0710 07:05:42.696941 10000 sched.cpp:934] Scheduler::resourceOffers took 1.002341ms
I0710 07:05:42.697464 10000 master.cpp:12470] Removing offer 8db40cec-43ef-41a1-89a4-4f7b877d8f13-O0
I0710 07:05:42.697743 10000 master.cpp:4636] Processing ACCEPT call for offers: [ 8db40cec-43ef-41a1-89a4-4f7b877d8f13-O0 ] on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0 at slave(522)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal) for framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082
I0710 07:05:42.697794 10000 master.cpp:3653] Authorizing framework principal 'test-principal' to launch task 26c92e4e-ef13-4984-9b06-b18f880decf3
W0710 07:05:42.698462 10003 validation.cpp:1640] Executor 'dummy' for task '26c92e4e-ef13-4984-9b06-b18f880decf3' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
W0710 07:05:42.698487 10003 validation.cpp:1652] Executor 'dummy' for task '26c92e4e-ef13-4984-9b06-b18f880decf3' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
I0710 07:05:42.698549 10003 master.cpp:4171] Adding executor 'dummy' with resources {} of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082 on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0 at slave(522)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.698590 10003 master.cpp:4197] Adding task 26c92e4e-ef13-4984-9b06-b18f880decf3 with resources cpus(allocated: role)(reservations: [(STATIC,role)]):1; mem(allocated: role)(reservations: [(STATIC,role)]):10 of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082 on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0 at slave(522)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.698686 10003 master.cpp:5615] Launching task 26c92e4e-ef13-4984-9b06-b18f880decf3 of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082 with resources [{"allocation_info":{"role":"role"},"name":"cpus","reservations":[{"role":"role","type":"STATIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"role"},"name":"mem","reservations":[{"role":"role","type":"STATIC"}],"scalar":{"value":10.0},"type":"SCALAR"}] on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0 at slave(522)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal) on new executor
I0710 07:05:42.698873 10000 hierarchical.cpp:1432] Allocation paused
I0710 07:05:42.698909 10000 hierarchical.cpp:1442] Allocation resumed
I0710 07:05:42.698961 10003 slave.cpp:2037] Got assigned task '26c92e4e-ef13-4984-9b06-b18f880decf3' for framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.699254 10003 slave.cpp:2411] Authorizing task '26c92e4e-ef13-4984-9b06-b18f880decf3' for framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.699282 10003 slave.cpp:9198] Authorizing framework principal 'test-principal' to launch task 26c92e4e-ef13-4984-9b06-b18f880decf3
I0710 07:05:42.699653 10003 slave.cpp:2854] Launching task '26c92e4e-ef13-4984-9b06-b18f880decf3' for framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.699702 10003 paths.cpp:801] Creating sandbox '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_xr6xQK/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166' for user 'root'
W0710 07:05:42.701002 9995 process.cpp:2877] Attempted to spawn already running process files@172.16.10.69:37082
I0710 07:05:42.701611 9995 containerizer.cpp:314] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
I0710 07:05:42.702396 10003 slave.cpp:9708] Launching executor 'dummy' of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 with resources [] in work directory '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_xr6xQK/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166'
I0710 07:05:42.702580 10003 slave.cpp:3080] Queued task '26c92e4e-ef13-4984-9b06-b18f880decf3' for executor 'dummy' of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.702809 10003 slave.cpp:3528] Launching container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166 for executor 'dummy' of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.703053 10003 slave.cpp:991] Successfully attached '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_xr6xQK/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166' to virtual path '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_xr6xQK/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/latest'
I0710 07:05:42.703063 10000 containerizer.cpp:1357] Starting container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166
I0710 07:05:42.703073 10003 slave.cpp:991] Successfully attached '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_xr6xQK/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166' to virtual path '/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/latest'
I0710 07:05:42.703085 10003 slave.cpp:991] Successfully attached '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_xr6xQK/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166' to virtual path '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_xr6xQK/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166'
I0710 07:05:42.703593 10000 containerizer.cpp:1529] Checkpointed ContainerConfig at '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_1IIJA6/containers/8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166/config'
I0710 07:05:42.703614 10000 containerizer.cpp:3277] Transitioning the state of container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166 from PROVISIONING to PREPARING
I0710 07:05:42.705749 9998 containerizer.cpp:2055] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"shell":true,"value":"sleep 3600"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.16.10.69:37082"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/RoleTest_RolesEndpointContainsConsumedQuota_xr6xQK/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiI4YTdkOWIwYS1lYmNmLTRmOGEtYWE3Yy0xYmJjYWRiMGMxNjYiLCJlaWQiOiJkdW1teSIsImZpZCI6IjhkYjQwY2VjLTQzZWYtNDFhMS04OWE0LTRmN2I4NzdkOGYxMy0wMDAwIn0.EfKHriG000A1P2MwWmmXnaLmTpTVdnl5-ZER_MFOkzQ"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"dummy"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(522)@172.16.10.69:37082"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/RoleTest_RolesEndpointContainsConsumedQuota_xr6xQK/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166"}]},"task_environment":{},"user":"root","working_directory":"/tmp/RoleTest_RolesEndpointContainsConsumedQuota_xr6xQK/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166"}" --pipe_read="22" --pipe_write="24" --runtime_directory="/tmp/RoleTest_RolesEndpointContainsConsumedQuota_1IIJA6/containers/8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166" --unshare_namespace_mnt="false"'
I0710 07:05:42.706059 10002 linux_launcher.cpp:492] Launching container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166 and cloning with namespaces
I0710 07:05:42.706065 9995 linux_launcher.cpp:144] Using /cgroup/freezer as the freezer hierarchy for the Linux launcher
I0710 07:05:42.710623 9995 provisioner.cpp:298] Using default backend 'copy'
I0710 07:05:42.712615 9995 cluster.cpp:510] Creating default 'local' authorizer
I0710 07:05:42.714180 10001 slave.cpp:265] Mesos agent started on (523)@172.16.10.69:37082
I0710 07:05:42.714211 10001 slave.cpp:266] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/1d0m6o/9m8Ujd/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/1d0m6o/9m8Ujd/credential" --default_role="*" --disallow_sharing_agent_ipc_namespace="false" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_ignore_runtime="false" --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/1d0m6o/9m8Ujd/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/1d0m6o/9m8Ujd/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/1d0m6o/9m8Ujd/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/1d0m6o/9m8Ujd/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --jwt_secret_key="/tmp/1d0m6o/9m8Ujd/jwt_secret_key" --launcher="linux" --launcher_dir="/home/centos/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-centos-6/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --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:10;mem:100;disk:0;ports:[]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/RoleTest_RolesEndpointContainsConsumedQuota_vKyXvR" --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/RoleTest_RolesEndpointContainsConsumedQuota_7tv0Hv" --zk_session_timeout="10secs"
I0710 07:05:42.714774 10001 credentials.hpp:86] Loading credential for authentication from '/tmp/1d0m6o/9m8Ujd/credential'
I0710 07:05:42.715389 10001 slave.cpp:298] Agent using credential for: test-principal
I0710 07:05:42.715405 10001 credentials.hpp:37] Loading credentials for authentication from '/tmp/1d0m6o/9m8Ujd/http_credentials'
I0710 07:05:42.715535 10001 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
I0710 07:05:42.715889 10001 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
I0710 07:05:42.716038 10001 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0710 07:05:42.716095 10001 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
I0710 07:05:42.716150 10001 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
I0710 07:05:42.716186 10001 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
I0710 07:05:42.716320 10001 disk_profile_adaptor.cpp:78] Creating default disk profile adaptor module
I0710 07:05:42.717517 9998 containerizer.cpp:3277] Transitioning the state of container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166 from PREPARING to ISOLATING
I0710 07:05:42.717968 9998 containerizer.cpp:3277] Transitioning the state of container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166 from ISOLATING to FETCHING
I0710 07:05:42.718013 9998 fetcher.cpp:369] Starting to fetch URIs for container: 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166, directory: /tmp/RoleTest_RolesEndpointContainsConsumedQuota_xr6xQK/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166
I0710 07:05:42.718289 9998 containerizer.cpp:3277] Transitioning the state of container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166 from FETCHING to RUNNING
I0710 07:05:42.718997 10001 slave.cpp:613] Agent resources: [{"name":"cpus","scalar":{"value":10.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":100.0},"type":"SCALAR"}]
I0710 07:05:42.719040 10001 slave.cpp:621] Agent attributes: [ ]
I0710 07:05:42.719048 10001 slave.cpp:630] Agent hostname: ip-172-16-10-69.ec2.internal
I0710 07:05:42.719467 10000 status_update_manager_process.hpp:379] Pausing operation status update manager
I0710 07:05:42.719682 9999 state.cpp:67] Recovering state from '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_7tv0Hv/meta'
I0710 07:05:42.719738 9999 slave.cpp:7246] Finished recovering checkpointed state from '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_7tv0Hv/meta', beginning agent recovery
I0710 07:05:42.719815 10001 task_status_update_manager.cpp:181] Pausing sending task status updates
I0710 07:05:42.719830 10001 task_status_update_manager.cpp:207] Recovering task status update manager
I0710 07:05:42.719913 10000 containerizer.cpp:796] Recovering Mesos containers
I0710 07:05:42.719964 10000 linux_launcher.cpp:286] Recovering Linux launcher
I0710 07:05:42.720106 10000 linux_launcher.cpp:343] Recovered container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166
I0710 07:05:42.720118 10000 linux_launcher.cpp:437] 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166 is a known orphaned container
I0710 07:05:42.720191 10000 containerizer.cpp:1122] Recovering isolators
I0710 07:05:42.720398 10000 containerizer.cpp:1161] Recovering provisioner
I0710 07:05:42.720507 10000 provisioner.cpp:498] Provisioner recovery complete
I0710 07:05:42.720561 10000 containerizer.cpp:1233] Cleaning up orphan container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166
I0710 07:05:42.720571 10000 containerizer.cpp:2575] Destroying container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166 in RUNNING state
I0710 07:05:42.720577 10000 containerizer.cpp:3277] Transitioning the state of container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166 from RUNNING to DESTROYING
I0710 07:05:42.720619 10000 containerizer.cpp:3116] Container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166 has exited
I0710 07:05:42.720666 10000 linux_launcher.cpp:576] Asked to destroy container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166
I0710 07:05:42.720688 10000 linux_launcher.cpp:618] Destroying cgroup '/cgroup/freezer/mesos/8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166'
I0710 07:05:42.720826 10000 cgroups.cpp:2854] Freezing cgroup /cgroup/freezer/mesos/8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166
I0710 07:05:42.720971 10000 cgroups.cpp:1242] Successfully froze cgroup /cgroup/freezer/mesos/8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166 after 123904ns
I0710 07:05:42.721382 9996 cgroups.cpp:2872] Thawing cgroup /cgroup/freezer/mesos/8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166
I0710 07:05:42.721483 9996 cgroups.cpp:1271] Successfully thawed cgroup /cgroup/freezer/mesos/8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166 after 79872ns
I0710 07:05:42.721833 9997 composing.cpp:339] Finished recovering all containerizers
I0710 07:05:42.721921 9997 slave.cpp:7708] Recovering executors
I0710 07:05:42.721946 9997 slave.cpp:7861] Finished recovery
I0710 07:05:42.722301 9999 task_status_update_manager.cpp:181] Pausing sending task status updates
I0710 07:05:42.722313 10002 slave.cpp:1258] New master detected at master@172.16.10.69:37082
I0710 07:05:42.722318 9999 status_update_manager_process.hpp:379] Pausing operation status update manager
I0710 07:05:42.722340 10002 slave.cpp:1323] Detecting new master
I0710 07:05:42.726434 9997 containerizer.cpp:3116] Container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166 has exited
I0710 07:05:42.726450 9997 containerizer.cpp:2575] Destroying container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166 in RUNNING state
I0710 07:05:42.726457 9997 containerizer.cpp:3277] Transitioning the state of container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166 from RUNNING to DESTROYING
I0710 07:05:42.727011 10000 posix.hpp:119] Ignoring cleanup request for unknown container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166
I0710 07:05:42.727073 9997 posix.hpp:119] Ignoring cleanup request for unknown container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166
I0710 07:05:42.727084 9999 linux_launcher.cpp:576] Asked to destroy container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166
W0710 07:05:42.727108 9999 linux_launcher.cpp:612] Couldn't find freezer cgroup for container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166 so assuming partially destroyed
I0710 07:05:42.727242 9999 provisioner.cpp:609] Ignoring destroy request for unknown container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166
I0710 07:05:42.727774 10002 provisioner.cpp:609] Ignoring destroy request for unknown container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166
I0710 07:05:42.728112 10002 slave.cpp:6613] Executor 'dummy' of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 terminated with signal Killed
I0710 07:05:42.728158 10002 slave.cpp:5545] Handling status update TASK_FAILED (Status UUID: ad5b35b9-3e9c-49ca-9e26-766a18bacf27) for task 26c92e4e-ef13-4984-9b06-b18f880decf3 of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 from @0.0.0.0:0
I0710 07:05:42.728368 10002 master.cpp:9087] Executor 'dummy' of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0 at slave(522)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal): terminated with signal Killed
E0710 07:05:42.728380 9998 slave.cpp:5876] Failed to update resources for container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166 of executor 'dummy' running task 26c92e4e-ef13-4984-9b06-b18f880decf3 on status update for terminal task, destroying container: Container not found
I0710 07:05:42.728389 10002 master.cpp:11957] Removing executor 'dummy' with resources {} of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0 at slave(522)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
W0710 07:05:42.728435 9998 composing.cpp:609] Attempted to destroy unknown container 8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166
I0710 07:05:42.728485 9999 sched.cpp:1144] Executor dummy on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0 exited with status 9
GMOCK WARNING:
Uninteresting mock function call - returning directly.
Function call: executorLost(0x7ffdf32e2180, @0x7fa4b40560d0 dummy, @0x7fa4b4042230 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0, 9)
NOTE: You can safely ignore the above warning unless this call should not happen. Do not suppress it by blindly adding an EXPECT_CALL() if you don't mean to enforce the call. See https://github.com/google/googletest/blob/master/googlemock/docs/CookBook.md#knowing-when-to-expect for details.
I0710 07:05:42.728511 9999 sched.cpp:1155] Scheduler::executorLost took 17655ns
I0710 07:05:42.728528 9998 task_status_update_manager.cpp:328] Received task status update TASK_FAILED (Status UUID: ad5b35b9-3e9c-49ca-9e26-766a18bacf27) for task 26c92e4e-ef13-4984-9b06-b18f880decf3 of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.728538 9998 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 26c92e4e-ef13-4984-9b06-b18f880decf3 of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.728665 9998 task_status_update_manager.cpp:383] Forwarding task status update TASK_FAILED (Status UUID: ad5b35b9-3e9c-49ca-9e26-766a18bacf27) for task 26c92e4e-ef13-4984-9b06-b18f880decf3 of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 to the agent
I0710 07:05:42.728718 10002 slave.cpp:6037] Forwarding the update TASK_FAILED (Status UUID: ad5b35b9-3e9c-49ca-9e26-766a18bacf27) for task 26c92e4e-ef13-4984-9b06-b18f880decf3 of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 to master@172.16.10.69:37082
I0710 07:05:42.728778 10002 slave.cpp:5930] Task status update manager successfully handled status update TASK_FAILED (Status UUID: ad5b35b9-3e9c-49ca-9e26-766a18bacf27) for task 26c92e4e-ef13-4984-9b06-b18f880decf3 of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.728833 10002 master.cpp:8750] Status update TASK_FAILED (Status UUID: ad5b35b9-3e9c-49ca-9e26-766a18bacf27) for task 26c92e4e-ef13-4984-9b06-b18f880decf3 of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 from agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0 at slave(522)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.728853 10002 master.cpp:8807] Forwarding status update TASK_FAILED (Status UUID: ad5b35b9-3e9c-49ca-9e26-766a18bacf27) for task 26c92e4e-ef13-4984-9b06-b18f880decf3 of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.728927 10002 master.cpp:11819] Updating the state of task 26c92e4e-ef13-4984-9b06-b18f880decf3 of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (latest state: TASK_FAILED, status update state: TASK_FAILED)
I0710 07:05:42.729089 10002 sched.cpp:1042] Scheduler::statusUpdate took 13020ns
I0710 07:05:42.729220 9999 master.cpp:6511] Processing ACKNOWLEDGE call for status ad5b35b9-3e9c-49ca-9e26-766a18bacf27 for task 26c92e4e-ef13-4984-9b06-b18f880decf3 of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082 on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0
I0710 07:05:42.729223 10002 hierarchical.cpp:1218] Recovered cpus(allocated: role)(reservations: [(STATIC,role)]):1; mem(allocated: role)(reservations: [(STATIC,role)]):10 (total: cpus(reservations: [(STATIC,role)]):1; mem(reservations: [(STATIC,role)]):10, allocated: {}) on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0 from framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.729259 9999 master.cpp:11917] Removing task 26c92e4e-ef13-4984-9b06-b18f880decf3 with resources cpus(allocated: role)(reservations: [(STATIC,role)]):1; mem(allocated: role)(reservations: [(STATIC,role)]):10 of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0 at slave(522)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.729396 9999 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: ad5b35b9-3e9c-49ca-9e26-766a18bacf27) for task 26c92e4e-ef13-4984-9b06-b18f880decf3 of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.729426 9999 task_status_update_manager.cpp:538] Cleaning up status update stream for task 26c92e4e-ef13-4984-9b06-b18f880decf3 of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.729501 9999 slave.cpp:4684] Task status update manager successfully handled status update acknowledgement (UUID: ad5b35b9-3e9c-49ca-9e26-766a18bacf27) for task 26c92e4e-ef13-4984-9b06-b18f880decf3 of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.729516 9999 slave.cpp:10377] Completing task 26c92e4e-ef13-4984-9b06-b18f880decf3
I0710 07:05:42.729526 9999 slave.cpp:6724] Cleaning up executor 'dummy' of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.729727 9999 slave.cpp:6853] Cleaning up framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.729831 9996 gc.cpp:95] Scheduling '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_xr6xQK/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/8a7d9b0a-ebcf-4f8a-aa7c-1bbcadb0c166' for gc 6.99999155561482days in the future
I0710 07:05:42.729882 9996 gc.cpp:95] Scheduling '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_xr6xQK/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy' for gc 6.99999155469926days in the future
I0710 07:05:42.729931 9996 gc.cpp:95] Scheduling '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_xr6xQK/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000' for gc 6.99999155361185days in the future
I0710 07:05:42.729969 9998 task_status_update_manager.cpp:289] Closing task status update streams for framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.732446 10002 slave.cpp:1350] Authenticating with master master@172.16.10.69:37082
I0710 07:05:42.732475 10002 slave.cpp:1359] Using default CRAM-MD5 authenticatee
I0710 07:05:42.732589 10002 authenticatee.cpp:121] Creating new client SASL connection
I0710 07:05:42.732667 10002 master.cpp:10380] Authenticating slave(523)@172.16.10.69:37082
I0710 07:05:42.732733 9996 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1052)@172.16.10.69:37082
I0710 07:05:42.732798 9998 authenticator.cpp:98] Creating new server SASL connection
I0710 07:05:42.732856 9998 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0710 07:05:42.732868 9998 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0710 07:05:42.732946 9998 authenticator.cpp:204] Received SASL authentication start
I0710 07:05:42.732995 9998 authenticator.cpp:326] Authentication requires more steps
I0710 07:05:42.733026 9998 authenticatee.cpp:259] Received SASL authentication step
I0710 07:05:42.733062 9998 authenticator.cpp:232] Received SASL authentication step
I0710 07:05:42.733076 9998 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-69' server FQDN: 'ip-172-16-10-69' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0710 07:05:42.733084 9998 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0710 07:05:42.733101 9998 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0710 07:05:42.733110 9998 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-69' server FQDN: 'ip-172-16-10-69' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0710 07:05:42.733117 9998 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0710 07:05:42.733124 9998 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0710 07:05:42.733155 9998 authenticator.cpp:318] Authentication success
I0710 07:05:42.733201 9998 authenticatee.cpp:299] Authentication success
I0710 07:05:42.733222 9996 master.cpp:10412] Successfully authenticated principal 'test-principal' at slave(523)@172.16.10.69:37082
I0710 07:05:42.733235 9998 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1052)@172.16.10.69:37082
I0710 07:05:42.733302 9996 slave.cpp:1450] Successfully authenticated with master master@172.16.10.69:37082
I0710 07:05:42.733389 9996 slave.cpp:1900] Will retry registration in 7.605677ms if necessary
I0710 07:05:42.733439 10000 master.cpp:6900] Received register agent message from slave(523)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.733523 10000 master.cpp:4099] Authorizing agent providing resources 'cpus:10; mem:100' with principal 'test-principal'
I0710 07:05:42.733680 10000 master.cpp:6967] Authorized registration of agent at slave(523)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.733718 10000 master.cpp:7082] Registering agent at slave(523)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal) with id 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1
I0710 07:05:42.733886 10001 registrar.cpp:487] Applied 1 operations in 44086ns; attempting to update the registry
I0710 07:05:42.734061 10001 registrar.cpp:544] Successfully updated the registry in 140032ns
I0710 07:05:42.734213 9996 master.cpp:7130] Admitted agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1 at slave(523)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.734323 9996 master.cpp:7175] Registered agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1 at slave(523)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal) with cpus:10; mem:100
I0710 07:05:42.734393 9996 slave.cpp:1483] Registered with master master@172.16.10.69:37082; given agent ID 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1
I0710 07:05:42.734426 9999 task_status_update_manager.cpp:188] Resuming sending task status updates
I0710 07:05:42.734390 10002 hierarchical.cpp:617] Added agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1 (ip-172-16-10-69.ec2.internal) with cpus:10; mem:100 (allocated: {})
I0710 07:05:42.734593 10002 hierarchical.cpp:1508] Performed allocation for 1 agents in 117981ns
I0710 07:05:42.734598 9996 slave.cpp:1518] Checkpointing SlaveInfo to '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_7tv0Hv/meta/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1/slave.info'
I0710 07:05:42.734688 9997 master.cpp:10195] Sending offers [ 8db40cec-43ef-41a1-89a4-4f7b877d8f13-O1 ] to framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082
I0710 07:05:42.734988 9997 sched.cpp:934] Scheduler::resourceOffers took 183157ns
I0710 07:05:42.735193 10002 status_update_manager_process.hpp:385] Resuming operation status update manager
I0710 07:05:42.735244 10000 master.cpp:12470] Removing offer 8db40cec-43ef-41a1-89a4-4f7b877d8f13-O1
I0710 07:05:42.735322 10000 master.cpp:4636] Processing ACCEPT call for offers: [ 8db40cec-43ef-41a1-89a4-4f7b877d8f13-O1 ] on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1 at slave(523)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal) for framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082
I0710 07:05:42.735352 10000 master.cpp:3653] Authorizing framework principal 'test-principal' to launch task 569d27cb-b353-42d0-8bd6-54c09f89f89d
I0710 07:05:42.735504 9996 slave.cpp:1570] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"FsYsMjR8RZaQN9nUJYAd2A=="},"slave_id":{"value":"8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1"},"update_oversubscribed_resources":false}
W0710 07:05:42.735776 9996 validation.cpp:1640] Executor 'dummy' for task '569d27cb-b353-42d0-8bd6-54c09f89f89d' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
W0710 07:05:42.735791 9996 validation.cpp:1652] Executor 'dummy' for task '569d27cb-b353-42d0-8bd6-54c09f89f89d' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
I0710 07:05:42.735822 9996 master.cpp:4171] Adding executor 'dummy' with resources {} of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082 on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1 at slave(523)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.735844 9996 master.cpp:4197] Adding task 569d27cb-b353-42d0-8bd6-54c09f89f89d with resources cpus(allocated: role):10; mem(allocated: role):100 of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082 on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1 at slave(523)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.735924 9996 master.cpp:5615] Launching task 569d27cb-b353-42d0-8bd6-54c09f89f89d of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082 with resources [{"allocation_info":{"role":"role"},"name":"cpus","scalar":{"value":10.0},"type":"SCALAR"},{"allocation_info":{"role":"role"},"name":"mem","scalar":{"value":100.0},"type":"SCALAR"}] on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1 at slave(523)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal) on new executor
I0710 07:05:42.736100 9996 master.cpp:8261] Ignoring update on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1 at slave(523)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal) as it reports no changes
I0710 07:05:42.736245 9996 slave.cpp:2037] Got assigned task '569d27cb-b353-42d0-8bd6-54c09f89f89d' for framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.736505 10000 hierarchical.cpp:1432] Allocation paused
I0710 07:05:42.736522 10000 hierarchical.cpp:1442] Allocation resumed
I0710 07:05:42.736714 9996 slave.cpp:2411] Authorizing task '569d27cb-b353-42d0-8bd6-54c09f89f89d' for framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.736740 9996 slave.cpp:9198] Authorizing framework principal 'test-principal' to launch task 569d27cb-b353-42d0-8bd6-54c09f89f89d
I0710 07:05:42.737113 9996 slave.cpp:2854] Launching task '569d27cb-b353-42d0-8bd6-54c09f89f89d' for framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.737164 9996 paths.cpp:801] Creating sandbox '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_7tv0Hv/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/e65bd434-1435-4c4c-a1cc-c0924710bcd5' for user 'root'
I0710 07:05:42.738385 9996 slave.cpp:9708] Launching executor 'dummy' of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 with resources [] in work directory '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_7tv0Hv/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/e65bd434-1435-4c4c-a1cc-c0924710bcd5'
I0710 07:05:42.738695 9996 slave.cpp:3080] Queued task '569d27cb-b353-42d0-8bd6-54c09f89f89d' for executor 'dummy' of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.739418 9996 slave.cpp:991] Successfully attached '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_7tv0Hv/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/e65bd434-1435-4c4c-a1cc-c0924710bcd5' to virtual path '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_7tv0Hv/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/latest'
I0710 07:05:42.739511 9996 slave.cpp:991] Successfully attached '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_7tv0Hv/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/e65bd434-1435-4c4c-a1cc-c0924710bcd5' to virtual path '/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/latest'
I0710 07:05:42.739528 9996 slave.cpp:991] Successfully attached '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_7tv0Hv/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/e65bd434-1435-4c4c-a1cc-c0924710bcd5' to virtual path '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_7tv0Hv/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/e65bd434-1435-4c4c-a1cc-c0924710bcd5'
I0710 07:05:42.739715 9996 slave.cpp:3528] Launching container e65bd434-1435-4c4c-a1cc-c0924710bcd5 for executor 'dummy' of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.739837 10002 containerizer.cpp:1357] Starting container e65bd434-1435-4c4c-a1cc-c0924710bcd5
W0710 07:05:42.740772 9995 process.cpp:2877] Attempted to spawn already running process files@172.16.10.69:37082
I0710 07:05:42.741189 9995 containerizer.cpp:314] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
I0710 07:05:42.741294 10002 containerizer.cpp:1529] Checkpointed ContainerConfig at '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_vKyXvR/containers/e65bd434-1435-4c4c-a1cc-c0924710bcd5/config'
I0710 07:05:42.741308 10002 containerizer.cpp:3277] Transitioning the state of container e65bd434-1435-4c4c-a1cc-c0924710bcd5 from PROVISIONING to PREPARING
I0710 07:05:42.742360 9997 containerizer.cpp:2055] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"shell":true,"value":"sleep 3600"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.16.10.69:37082"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/RoleTest_RolesEndpointContainsConsumedQuota_7tv0Hv/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/e65bd434-1435-4c4c-a1cc-c0924710bcd5"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiJlNjViZDQzNC0xNDM1LTRjNGMtYTFjYy1jMDkyNDcxMGJjZDUiLCJlaWQiOiJkdW1teSIsImZpZCI6IjhkYjQwY2VjLTQzZWYtNDFhMS04OWE0LTRmN2I4NzdkOGYxMy0wMDAwIn0.QI3SX1Bm7RFY5Z9unqU5UG8U2NTHMNFxdKrqWq87IIY"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"dummy"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(523)@172.16.10.69:37082"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/RoleTest_RolesEndpointContainsConsumedQuota_7tv0Hv/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/e65bd434-1435-4c4c-a1cc-c0924710bcd5"}]},"task_environment":{},"user":"root","working_directory":"/tmp/RoleTest_RolesEndpointContainsConsumedQuota_7tv0Hv/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/e65bd434-1435-4c4c-a1cc-c0924710bcd5"}" --pipe_read="28" --pipe_write="41" --runtime_directory="/tmp/RoleTest_RolesEndpointContainsConsumedQuota_vKyXvR/containers/e65bd434-1435-4c4c-a1cc-c0924710bcd5" --unshare_namespace_mnt="false"'
I0710 07:05:42.742801 10000 linux_launcher.cpp:492] Launching container e65bd434-1435-4c4c-a1cc-c0924710bcd5 and cloning with namespaces
I0710 07:05:42.751811 9997 containerizer.cpp:3277] Transitioning the state of container e65bd434-1435-4c4c-a1cc-c0924710bcd5 from PREPARING to ISOLATING
I0710 07:05:42.753885 9997 containerizer.cpp:3277] Transitioning the state of container e65bd434-1435-4c4c-a1cc-c0924710bcd5 from ISOLATING to FETCHING
I0710 07:05:42.753968 9997 fetcher.cpp:369] Starting to fetch URIs for container: e65bd434-1435-4c4c-a1cc-c0924710bcd5, directory: /tmp/RoleTest_RolesEndpointContainsConsumedQuota_7tv0Hv/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/e65bd434-1435-4c4c-a1cc-c0924710bcd5
I0710 07:05:42.754302 9997 containerizer.cpp:3277] Transitioning the state of container e65bd434-1435-4c4c-a1cc-c0924710bcd5 from FETCHING to RUNNING
I0710 07:05:42.757205 9995 linux_launcher.cpp:144] Using /cgroup/freezer as the freezer hierarchy for the Linux launcher
I0710 07:05:42.757709 9995 provisioner.cpp:298] Using default backend 'copy'
I0710 07:05:42.758428 9995 cluster.cpp:510] Creating default 'local' authorizer
I0710 07:05:42.760093 9998 slave.cpp:265] Mesos agent started on (524)@172.16.10.69:37082
I0710 07:05:42.760107 9998 slave.cpp:266] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/1d0m6o/nhq4g2/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/1d0m6o/nhq4g2/credential" --default_role="*" --disallow_sharing_agent_ipc_namespace="false" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_ignore_runtime="false" --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/1d0m6o/nhq4g2/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/1d0m6o/nhq4g2/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/1d0m6o/nhq4g2/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/1d0m6o/nhq4g2/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --jwt_secret_key="/tmp/1d0m6o/nhq4g2/jwt_secret_key" --launcher="linux" --launcher_dir="/home/centos/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-centos-6/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --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(role):100;mem(role):1000;cpus:1000;mem:10000;;disk:0;ports:[]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/RoleTest_RolesEndpointContainsConsumedQuota_y8F3mG" --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/RoleTest_RolesEndpointContainsConsumedQuota_1vh3sk" --zk_session_timeout="10secs"
I0710 07:05:42.760334 9998 credentials.hpp:86] Loading credential for authentication from '/tmp/1d0m6o/nhq4g2/credential'
I0710 07:05:42.760402 9998 slave.cpp:298] Agent using credential for: test-principal
I0710 07:05:42.760412 9998 credentials.hpp:37] Loading credentials for authentication from '/tmp/1d0m6o/nhq4g2/http_credentials'
I0710 07:05:42.760509 9998 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
I0710 07:05:42.760550 9998 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
I0710 07:05:42.760598 9998 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0710 07:05:42.760618 9998 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
I0710 07:05:42.760644 9998 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
I0710 07:05:42.760660 9998 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
I0710 07:05:42.760718 9998 disk_profile_adaptor.cpp:78] Creating default disk profile adaptor module
I0710 07:05:42.761492 9998 slave.cpp:613] Agent resources: [{"name":"cpus","reservations":[{"role":"role","type":"STATIC"}],"scalar":{"value":100.0},"type":"SCALAR"},{"name":"mem","reservations":[{"role":"role","type":"STATIC"}],"scalar":{"value":1000.0},"type":"SCALAR"},{"name":"cpus","scalar":{"value":1000.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":10000.0},"type":"SCALAR"}]
I0710 07:05:42.761574 9998 slave.cpp:621] Agent attributes: [ ]
I0710 07:05:42.761582 9998 slave.cpp:630] Agent hostname: ip-172-16-10-69.ec2.internal
I0710 07:05:42.761935 10002 task_status_update_manager.cpp:181] Pausing sending task status updates
I0710 07:05:42.761960 10002 status_update_manager_process.hpp:379] Pausing operation status update manager
I0710 07:05:42.762143 9998 state.cpp:67] Recovering state from '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_1vh3sk/meta'
I0710 07:05:42.762202 9998 slave.cpp:7246] Finished recovering checkpointed state from '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_1vh3sk/meta', beginning agent recovery
I0710 07:05:42.762287 9998 task_status_update_manager.cpp:207] Recovering task status update manager
I0710 07:05:42.762373 10001 containerizer.cpp:796] Recovering Mesos containers
I0710 07:05:42.762420 9998 linux_launcher.cpp:286] Recovering Linux launcher
I0710 07:05:42.762591 9998 linux_launcher.cpp:343] Recovered container e65bd434-1435-4c4c-a1cc-c0924710bcd5
I0710 07:05:42.762603 9998 linux_launcher.cpp:437] e65bd434-1435-4c4c-a1cc-c0924710bcd5 is a known orphaned container
I0710 07:05:42.762668 9998 containerizer.cpp:1122] Recovering isolators
I0710 07:05:42.762888 9998 containerizer.cpp:1161] Recovering provisioner
I0710 07:05:42.763167 10003 provisioner.cpp:498] Provisioner recovery complete
I0710 07:05:42.763443 9998 containerizer.cpp:1233] Cleaning up orphan container e65bd434-1435-4c4c-a1cc-c0924710bcd5
I0710 07:05:42.763458 9998 containerizer.cpp:2575] Destroying container e65bd434-1435-4c4c-a1cc-c0924710bcd5 in RUNNING state
I0710 07:05:42.763484 9998 containerizer.cpp:3277] Transitioning the state of container e65bd434-1435-4c4c-a1cc-c0924710bcd5 from RUNNING to DESTROYING
I0710 07:05:42.763531 9998 containerizer.cpp:3116] Container e65bd434-1435-4c4c-a1cc-c0924710bcd5 has exited
I0710 07:05:42.763595 10003 linux_launcher.cpp:576] Asked to destroy container e65bd434-1435-4c4c-a1cc-c0924710bcd5
I0710 07:05:42.763646 10003 linux_launcher.cpp:618] Destroying cgroup '/cgroup/freezer/mesos/e65bd434-1435-4c4c-a1cc-c0924710bcd5'
I0710 07:05:42.763885 10003 cgroups.cpp:2854] Freezing cgroup /cgroup/freezer/mesos/e65bd434-1435-4c4c-a1cc-c0924710bcd5
I0710 07:05:42.764073 10003 cgroups.cpp:1242] Successfully froze cgroup /cgroup/freezer/mesos/e65bd434-1435-4c4c-a1cc-c0924710bcd5 after 141056ns
I0710 07:05:42.764142 10003 composing.cpp:339] Finished recovering all containerizers
I0710 07:05:42.764317 10003 cgroups.cpp:2872] Thawing cgroup /cgroup/freezer/mesos/e65bd434-1435-4c4c-a1cc-c0924710bcd5
I0710 07:05:42.764420 10003 slave.cpp:7708] Recovering executors
I0710 07:05:42.764467 10003 slave.cpp:7861] Finished recovery
I0710 07:05:42.765122 9996 slave.cpp:1258] New master detected at master@172.16.10.69:37082
I0710 07:05:42.765321 9997 task_status_update_manager.cpp:181] Pausing sending task status updates
I0710 07:05:42.765341 9997 status_update_manager_process.hpp:379] Pausing operation status update manager
I0710 07:05:42.765812 10003 cgroups.cpp:1271] Successfully thawed cgroup /cgroup/freezer/mesos/e65bd434-1435-4c4c-a1cc-c0924710bcd5 after 1.467904ms
I0710 07:05:42.766065 9996 slave.cpp:1323] Detecting new master
I0710 07:05:42.766970 10002 slave.cpp:1350] Authenticating with master master@172.16.10.69:37082
I0710 07:05:42.767000 10002 slave.cpp:1359] Using default CRAM-MD5 authenticatee
I0710 07:05:42.767086 10002 authenticatee.cpp:121] Creating new client SASL connection
I0710 07:05:42.767170 10002 master.cpp:10380] Authenticating slave(524)@172.16.10.69:37082
I0710 07:05:42.767230 10002 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1053)@172.16.10.69:37082
I0710 07:05:42.767287 10002 authenticator.cpp:98] Creating new server SASL connection
I0710 07:05:42.767347 10002 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0710 07:05:42.767360 10002 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0710 07:05:42.767390 10002 authenticator.cpp:204] Received SASL authentication start
I0710 07:05:42.767428 10002 authenticator.cpp:326] Authentication requires more steps
I0710 07:05:42.767462 10002 authenticatee.cpp:259] Received SASL authentication step
I0710 07:05:42.767513 10001 authenticator.cpp:232] Received SASL authentication step
I0710 07:05:42.767534 10001 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-69' server FQDN: 'ip-172-16-10-69' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0710 07:05:42.767544 10001 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0710 07:05:42.767558 10001 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0710 07:05:42.767567 10001 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-69' server FQDN: 'ip-172-16-10-69' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0710 07:05:42.767573 10001 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0710 07:05:42.767578 10001 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0710 07:05:42.767591 10001 authenticator.cpp:318] Authentication success
I0710 07:05:42.767629 10003 authenticatee.cpp:299] Authentication success
I0710 07:05:42.767637 9999 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1053)@172.16.10.69:37082
I0710 07:05:42.767684 10003 slave.cpp:1450] Successfully authenticated with master master@172.16.10.69:37082
I0710 07:05:42.767706 10001 master.cpp:10412] Successfully authenticated principal 'test-principal' at slave(524)@172.16.10.69:37082
I0710 07:05:42.767781 10003 slave.cpp:1900] Will retry registration in 13.7987ms if necessary
I0710 07:05:42.767853 10003 master.cpp:6900] Received register agent message from slave(524)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.767944 10003 master.cpp:4099] Authorizing agent providing resources 'cpus(reservations: [(STATIC,role)]):100; mem(reservations: [(STATIC,role)]):1000; cpus:1000; mem:10000' with principal 'test-principal'
I0710 07:05:42.768015 10003 master.cpp:3721] Authorizing principal 'test-principal' to reserve resources 'cpus(reservations: [(STATIC,role)]):100; mem(reservations: [(STATIC,role)]):1000; cpus:1000; mem:10000'
I0710 07:05:42.768442 10003 master.cpp:6967] Authorized registration of agent at slave(524)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.768492 10003 master.cpp:7082] Registering agent at slave(524)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal) with id 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S2
I0710 07:05:42.768646 10003 registrar.cpp:487] Applied 1 operations in 54580ns; attempting to update the registry
I0710 07:05:42.768805 10003 registrar.cpp:544] Successfully updated the registry in 134144ns
I0710 07:05:42.768859 10003 master.cpp:7130] Admitted agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S2 at slave(524)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.769022 10003 master.cpp:7175] Registered agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S2 at slave(524)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal) with cpus(reservations: [(STATIC,role)]):100; mem(reservations: [(STATIC,role)]):1000; cpus:1000; mem:10000
I0710 07:05:42.769095 10003 slave.cpp:1483] Registered with master master@172.16.10.69:37082; given agent ID 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S2
I0710 07:05:42.769098 9998 hierarchical.cpp:617] Added agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S2 (ip-172-16-10-69.ec2.internal) with cpus(reservations: [(STATIC,role)]):100; mem(reservations: [(STATIC,role)]):1000; cpus:1000; mem:10000 (allocated: {})
I0710 07:05:42.769269 9998 hierarchical.cpp:1508] Performed allocation for 1 agents in 117869ns
I0710 07:05:42.769294 9998 task_status_update_manager.cpp:188] Resuming sending task status updates
I0710 07:05:42.769302 10003 slave.cpp:1518] Checkpointing SlaveInfo to '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_1vh3sk/meta/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S2/slave.info'
I0710 07:05:42.769402 9998 master.cpp:10195] Sending offers [ 8db40cec-43ef-41a1-89a4-4f7b877d8f13-O2 ] to framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082
I0710 07:05:42.769469 9998 status_update_manager_process.hpp:385] Resuming operation status update manager
I0710 07:05:42.769570 9998 sched.cpp:934] Scheduler::resourceOffers took 16191ns
I0710 07:05:42.769608 10003 slave.cpp:1570] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"NxZjtIFYTJmNFPUgPJ4Odw=="},"slave_id":{"value":"8db40cec-43ef-41a1-89a4-4f7b877d8f13-S2"},"update_oversubscribed_resources":false}
I0710 07:05:42.769840 10003 master.cpp:8261] Ignoring update on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S2 at slave(524)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal) as it reports no changes
I0710 07:05:42.770727 10001 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/roles'
I0710 07:05:42.771086 10001 http.cpp:1115] HTTP GET for /master/roles from 172.16.10.69:47106
../../src/tests/role_tests.cpp:615: Failure
Expected: *expected
Which is: 24-byte object <03-00 00-00 57-55 00-00 A0-DD DE-4C 57-55 00-00 01-00 00-00 00-00 00-00>
To be equal to: *parse
Which is: 24-byte object <03-00 00-00 00-00 00-00 50-D8 DE-4C 57-55 00-00 00-00 00-00 00-00 00-00>
expected {"roles":[{"frameworks":["8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000"],"name":"role","quota":{"consumed":{"cpus":111.0,"mem":1110.0},"guarantee":{},"limit":{},"role":"role"},"resources":{"cpus":1111.0,"disk":0,"gpus":0,"mem":11110.0},"weight":1.0}]} vs actual {"roles":[{"frameworks":["8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000"],"name":"role","quota":{"consumed":{"cpus":111.0,"mem":1110.0},"guarantee":{},"limit":{},"role":"role"},"resources":{"cpus":1110.0,"disk":0.0,"gpus":0.0,"mem":11100.0},"weight":1.0}]}
I0710 07:05:42.772022 9995 slave.cpp:912] Agent terminating
I0710 07:05:42.782775 9997 master.cpp:1295] Agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S2 at slave(524)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal) disconnected
I0710 07:05:42.782796 9997 master.cpp:3379] Disconnecting agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S2 at slave(524)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.782812 9997 master.cpp:3398] Deactivating agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S2 at slave(524)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.782881 10000 hierarchical.cpp:799] Agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S2 deactivated
I0710 07:05:42.782927 9997 master.cpp:12470] Removing offer 8db40cec-43ef-41a1-89a4-4f7b877d8f13-O2
I0710 07:05:42.782994 9997 sched.cpp:960] Rescinded offer 8db40cec-43ef-41a1-89a4-4f7b877d8f13-O2
I0710 07:05:42.782990 10000 hierarchical.cpp:1218] Recovered cpus(allocated: role)(reservations: [(STATIC,role)]):100; mem(allocated: role)(reservations: [(STATIC,role)]):1000; cpus(allocated: role):1000; mem(allocated: role):10000 (total: cpus(reservations: [(STATIC,role)]):100; mem(reservations: [(STATIC,role)]):1000; cpus:1000; mem:10000, allocated: {}) on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S2 from framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
GMOCK WARNING:
Uninteresting mock function call - returning directly.
Function call: offerRescinded(0x7ffdf32e2180, @0x7fa4ac05e8c8 8db40cec-43ef-41a1-89a4-4f7b877d8f13-O2)
NOTE: You can safely ignore the above warning unless this call should not happen. Do not suppress it by blindly adding an EXPECT_CALL() if you don't mean to enforce the call. See https://github.com/google/googletest/blob/master/googlemock/docs/CookBook.md#knowing-when-to-expect for details.
I0710 07:05:42.783027 9997 sched.cpp:971] Scheduler::offerRescinded took 19723ns
I0710 07:05:42.827190 9999 containerizer.cpp:3116] Container e65bd434-1435-4c4c-a1cc-c0924710bcd5 has exited
I0710 07:05:42.827210 9999 containerizer.cpp:2575] Destroying container e65bd434-1435-4c4c-a1cc-c0924710bcd5 in RUNNING state
I0710 07:05:42.827219 9999 containerizer.cpp:3277] Transitioning the state of container e65bd434-1435-4c4c-a1cc-c0924710bcd5 from RUNNING to DESTROYING
I0710 07:05:42.827332 9999 linux_launcher.cpp:576] Asked to destroy container e65bd434-1435-4c4c-a1cc-c0924710bcd5
W0710 07:05:42.827359 9999 linux_launcher.cpp:612] Couldn't find freezer cgroup for container e65bd434-1435-4c4c-a1cc-c0924710bcd5 so assuming partially destroyed
I0710 07:05:42.827975 10002 posix.hpp:119] Ignoring cleanup request for unknown container e65bd434-1435-4c4c-a1cc-c0924710bcd5
I0710 07:05:42.828035 9997 posix.hpp:119] Ignoring cleanup request for unknown container e65bd434-1435-4c4c-a1cc-c0924710bcd5
I0710 07:05:42.828187 10001 provisioner.cpp:609] Ignoring destroy request for unknown container e65bd434-1435-4c4c-a1cc-c0924710bcd5
I0710 07:05:42.828363 9999 provisioner.cpp:609] Ignoring destroy request for unknown container e65bd434-1435-4c4c-a1cc-c0924710bcd5
I0710 07:05:42.828725 9999 slave.cpp:6613] Executor 'dummy' of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 terminated with signal Killed
I0710 07:05:42.828778 9999 slave.cpp:5545] Handling status update TASK_FAILED (Status UUID: 68222006-6847-43f1-a92a-00c530a4b600) for task 569d27cb-b353-42d0-8bd6-54c09f89f89d of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 from @0.0.0.0:0
I0710 07:05:42.829021 9999 master.cpp:9087] Executor 'dummy' of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1 at slave(523)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal): terminated with signal Killed
E0710 07:05:42.829030 10000 slave.cpp:5876] Failed to update resources for container e65bd434-1435-4c4c-a1cc-c0924710bcd5 of executor 'dummy' running task 569d27cb-b353-42d0-8bd6-54c09f89f89d on status update for terminal task, destroying container: Container not found
I0710 07:05:42.829043 9999 master.cpp:11957] Removing executor 'dummy' with resources {} of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1 at slave(523)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
W0710 07:05:42.829088 10000 composing.cpp:609] Attempted to destroy unknown container e65bd434-1435-4c4c-a1cc-c0924710bcd5
I0710 07:05:42.829113 9999 task_status_update_manager.cpp:328] Received task status update TASK_FAILED (Status UUID: 68222006-6847-43f1-a92a-00c530a4b600) for task 569d27cb-b353-42d0-8bd6-54c09f89f89d of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.829131 9999 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 569d27cb-b353-42d0-8bd6-54c09f89f89d of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.829141 10000 sched.cpp:1144] Executor dummy on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1 exited with status 9
GMOCK WARNING:
Uninteresting mock function call - returning directly.
Function call: executorLost(0x7ffdf32e2180, @0x7fa4a4013590 dummy, @0x7fa4a40ace00 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1, 9)
NOTE: You can safely ignore the above warning unless this call should not happen. Do not suppress it by blindly adding an EXPECT_CALL() if you don't mean to enforce the call. See https://github.com/google/googletest/blob/master/googlemock/docs/CookBook.md#knowing-when-to-expect for details.
I0710 07:05:42.829171 10000 sched.cpp:1155] Scheduler::executorLost took 19974ns
I0710 07:05:42.829339 9999 task_status_update_manager.cpp:383] Forwarding task status update TASK_FAILED (Status UUID: 68222006-6847-43f1-a92a-00c530a4b600) for task 569d27cb-b353-42d0-8bd6-54c09f89f89d of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 to the agent
I0710 07:05:42.829401 9999 slave.cpp:6037] Forwarding the update TASK_FAILED (Status UUID: 68222006-6847-43f1-a92a-00c530a4b600) for task 569d27cb-b353-42d0-8bd6-54c09f89f89d of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 to master@172.16.10.69:37082
I0710 07:05:42.829454 9999 slave.cpp:5930] Task status update manager successfully handled status update TASK_FAILED (Status UUID: 68222006-6847-43f1-a92a-00c530a4b600) for task 569d27cb-b353-42d0-8bd6-54c09f89f89d of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.829504 9999 master.cpp:8750] Status update TASK_FAILED (Status UUID: 68222006-6847-43f1-a92a-00c530a4b600) for task 569d27cb-b353-42d0-8bd6-54c09f89f89d of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 from agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1 at slave(523)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.829519 9999 master.cpp:8807] Forwarding status update TASK_FAILED (Status UUID: 68222006-6847-43f1-a92a-00c530a4b600) for task 569d27cb-b353-42d0-8bd6-54c09f89f89d of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.829567 9999 master.cpp:11819] Updating the state of task 569d27cb-b353-42d0-8bd6-54c09f89f89d of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (latest state: TASK_FAILED, status update state: TASK_FAILED)
I0710 07:05:42.829679 9999 sched.cpp:1042] Scheduler::statusUpdate took 10656ns
I0710 07:05:42.829782 9999 hierarchical.cpp:1218] Recovered cpus(allocated: role):10; mem(allocated: role):100 (total: cpus:10; mem:100, allocated: {}) on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1 from framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.829838 9999 master.cpp:6511] Processing ACKNOWLEDGE call for status 68222006-6847-43f1-a92a-00c530a4b600 for task 569d27cb-b353-42d0-8bd6-54c09f89f89d of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082 on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1
I0710 07:05:42.829860 9999 master.cpp:11917] Removing task 569d27cb-b353-42d0-8bd6-54c09f89f89d with resources cpus(allocated: role):10; mem(allocated: role):100 of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 on agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1 at slave(523)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.830682 9999 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 68222006-6847-43f1-a92a-00c530a4b600) for task 569d27cb-b353-42d0-8bd6-54c09f89f89d of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.830718 9999 task_status_update_manager.cpp:538] Cleaning up status update stream for task 569d27cb-b353-42d0-8bd6-54c09f89f89d of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.830792 9999 slave.cpp:4684] Task status update manager successfully handled status update acknowledgement (UUID: 68222006-6847-43f1-a92a-00c530a4b600) for task 569d27cb-b353-42d0-8bd6-54c09f89f89d of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.830806 9999 slave.cpp:10377] Completing task 569d27cb-b353-42d0-8bd6-54c09f89f89d
I0710 07:05:42.830814 9999 slave.cpp:6724] Cleaning up executor 'dummy' of framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.831112 10000 gc.cpp:95] Scheduling '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_7tv0Hv/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy/runs/e65bd434-1435-4c4c-a1cc-c0924710bcd5' for gc 6.99999041237333days in the future
I0710 07:05:42.831207 9999 slave.cpp:6853] Cleaning up framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.831210 9998 gc.cpp:95] Scheduling '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_7tv0Hv/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000/executors/dummy' for gc 6.99999041237333days in the future
I0710 07:05:42.831255 9998 task_status_update_manager.cpp:289] Closing task status update streams for framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.831547 10001 gc.cpp:95] Scheduling '/tmp/RoleTest_RolesEndpointContainsConsumedQuota_7tv0Hv/slaves/8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1/frameworks/8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000' for gc 6.99999041237333days in the future
I0710 07:05:42.835628 10000 slave.cpp:912] Agent terminating
I0710 07:05:42.835824 9996 master.cpp:1295] Agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1 at slave(523)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal) disconnected
I0710 07:05:42.835842 9996 master.cpp:3379] Disconnecting agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1 at slave(523)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.835861 9996 master.cpp:3398] Deactivating agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1 at slave(523)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.835888 10000 hierarchical.cpp:799] Agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1 deactivated
I0710 07:05:42.842595 9998 master.cpp:1410] Framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082 disconnected
I0710 07:05:42.842618 9998 master.cpp:3342] Deactivating framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082
I0710 07:05:42.842640 9998 master.cpp:3319] Disconnecting framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082
I0710 07:05:42.842655 9998 master.cpp:1425] Giving framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082 0ns to failover
I0710 07:05:42.842986 9997 hierarchical.cpp:475] Deactivated framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.843145 9996 master.cpp:9987] Framework failover timeout, removing framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082
I0710 07:05:42.843192 9996 master.cpp:10979] Removing framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 (default) at scheduler-c1197694-9c80-4659-ba29-891d2bcb6a32@172.16.10.69:37082
I0710 07:05:42.843421 9999 hierarchical.cpp:1432] Allocation paused
I0710 07:05:42.843487 9999 hierarchical.cpp:417] Removed framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.843492 10000 slave.cpp:3908] Asked to shut down framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000 by master@172.16.10.69:37082
I0710 07:05:42.843508 10000 slave.cpp:3923] Cannot shut down unknown framework 8db40cec-43ef-41a1-89a4-4f7b877d8f13-0000
I0710 07:05:42.843531 9999 hierarchical.cpp:1442] Allocation resumed
I0710 07:05:42.851032 9995 slave.cpp:912] Agent terminating
I0710 07:05:42.851421 10001 master.cpp:1295] Agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0 at slave(522)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal) disconnected
I0710 07:05:42.851441 10001 master.cpp:3379] Disconnecting agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0 at slave(522)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.851459 10001 master.cpp:3398] Deactivating agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0 at slave(522)@172.16.10.69:37082 (ip-172-16-10-69.ec2.internal)
I0710 07:05:42.851487 9997 hierarchical.cpp:799] Agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0 deactivated
I0710 07:05:42.853623 9997 master.cpp:1135] Master terminating
I0710 07:05:42.853726 10000 hierarchical.cpp:775] Removed all filters for agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S2
I0710 07:05:42.853737 10000 hierarchical.cpp:650] Removed agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S2
I0710 07:05:42.853775 10000 hierarchical.cpp:775] Removed all filters for agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1
I0710 07:05:42.853780 10000 hierarchical.cpp:650] Removed agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S1
I0710 07:05:42.854012 10003 hierarchical.cpp:775] Removed all filters for agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0
I0710 07:05:42.854027 10003 hierarchical.cpp:650] Removed agent 8db40cec-43ef-41a1-89a4-4f7b877d8f13-S0
[ FAILED ] RoleTest.RolesEndpointContainsConsumedQuota (199 ms)
Bug
Major