Details
-
Bug
-
Status: Open
-
Major
-
Resolution: Unresolved
-
1.8.0
-
None
Description
The following I saw in a macOS run:
14:39:11 [ RUN ] ContentType/AgentAPITest.GetFrameworks/1 14:39:11 I1119 06:39:15.264891 2668864320 cluster.cpp:173] Creating default 'local' authorizer 14:39:11 I1119 06:39:15.266228 170434560 master.cpp:413] Master be3714c6-f7ac-4dce-8791-7bddc37889d4 (Jenkinss-Mac-mini.local) started on 10.0.49.4:61227 14:39:11 I1119 06:39:15.266257 170434560 master.cpp:416] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1000secs" --allocator="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/private/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/dFgHko/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="/private/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/dFgHko/master" --zk_session_timeout="10secs" 14:39:11 I1119 06:39:15.266446 170434560 master.cpp:465] Master only allowing authenticated frameworks to register 14:39:11 I1119 06:39:15.266455 170434560 master.cpp:471] Master only allowing authenticated agents to register 14:39:11 I1119 06:39:15.266460 170434560 master.cpp:477] Master only allowing authenticated HTTP frameworks to register 14:39:11 I1119 06:39:15.266484 170434560 credentials.hpp:37] Loading credentials for authentication from '/private/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/dFgHko/credentials' 14:39:11 I1119 06:39:15.266654 170434560 master.cpp:521] Using default 'crammd5' authenticator 14:39:11 I1119 06:39:15.266732 170434560 http.cpp:1042] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' 14:39:11 I1119 06:39:15.266801 170434560 http.cpp:1042] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' 14:39:11 I1119 06:39:15.266851 170434560 http.cpp:1042] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' 14:39:11 I1119 06:39:15.266904 170434560 master.cpp:602] Authorization enabled 14:39:11 I1119 06:39:15.267139 169361408 hierarchical.cpp:175] Initialized hierarchical allocator process 14:39:11 I1119 06:39:15.267357 170971136 whitelist_watcher.cpp:77] No whitelist given 14:39:11 I1119 06:39:15.268975 170971136 master.cpp:2105] Elected as the leading master! 14:39:11 I1119 06:39:15.269001 170971136 master.cpp:1660] Recovering from registrar 14:39:11 I1119 06:39:15.269045 169897984 registrar.cpp:339] Recovering registrar 14:39:11 I1119 06:39:15.269253 169361408 registrar.cpp:383] Successfully fetched the registry (0B) in 187136ns 14:39:11 I1119 06:39:15.269342 169361408 registrar.cpp:487] Applied 1 operations in 22753ns; attempting to update the registry 14:39:11 I1119 06:39:15.269572 168288256 registrar.cpp:544] Successfully updated the registry in 187136ns 14:39:11 I1119 06:39:15.269637 168288256 registrar.cpp:416] Successfully recovered registrar 14:39:11 I1119 06:39:15.269793 170434560 master.cpp:1774] Recovered 0 agents from the registry (155B); allowing 10mins for agents to reregister 14:39:11 I1119 06:39:15.269825 167215104 hierarchical.cpp:215] Skipping recovery of hierarchical allocator: nothing to recover 14:39:11 W1119 06:39:15.272145 2668864320 process.cpp:2829] Attempted to spawn already running process files@10.0.49.4:61227 14:39:11 I1119 06:39:15.272856 2668864320 containerizer.cpp:305] Using isolation { environment_secret, filesystem/posix, posix/mem, posix/cpu } 14:39:11 I1119 06:39:15.273074 2668864320 provisioner.cpp:298] Using default backend 'copy' 14:39:11 I1119 06:39:15.273936 2668864320 cluster.cpp:485] Creating default 'local' authorizer 14:39:11 I1119 06:39:15.275010 169361408 slave.cpp:267] Mesos agent started on (828)@10.0.49.4:61227 14:39:11 I1119 06:39:15.275039 169361408 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/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" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/credential" --default_role="*" --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="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/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="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/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="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --jwt_secret_key="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/jwt_secret_key" --launcher="posix" --launcher_dir="/Users/jenkins/workspace/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mac/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" --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]" --runtime_dir="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --version="false" --work_dir="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73" --zk_session_timeout="10secs" 14:39:11 I1119 06:39:15.275311 169361408 credentials.hpp:86] Loading credential for authentication from '/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/credential' 14:39:11 W1119 06:39:15.275388 2668864320 process.cpp:2829] Attempted to spawn already running process version@10.0.49.4:61227 14:39:11 I1119 06:39:15.275434 169361408 slave.cpp:300] Agent using credential for: test-principal 14:39:11 I1119 06:39:15.275447 169361408 credentials.hpp:37] Loading credentials for authentication from '/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/http_credentials' 14:39:11 I1119 06:39:15.275643 169361408 http.cpp:1042] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor' 14:39:11 I1119 06:39:15.275707 169361408 http.cpp:1063] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor' 14:39:11 I1119 06:39:15.275797 169361408 http.cpp:1042] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' 14:39:11 I1119 06:39:15.275840 169361408 http.cpp:1063] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly' 14:39:11 I1119 06:39:15.275915 169361408 http.cpp:1042] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' 14:39:11 I1119 06:39:15.275976 169361408 http.cpp:1063] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite' 14:39:11 I1119 06:39:15.276202 169361408 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module 14:39:11 I1119 06:39:15.276495 169361408 slave.cpp:615] 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"}] 14:39:11 I1119 06:39:15.276616 169361408 slave.cpp:623] Agent attributes: [ ] 14:39:11 I1119 06:39:15.276629 169361408 slave.cpp:632] Agent hostname: Jenkinss-Mac-mini.local 14:39:11 I1119 06:39:15.276681 2668864320 sched.cpp:232] Version: 1.8.0 14:39:11 I1119 06:39:15.276784 167751680 task_status_update_manager.cpp:181] Pausing sending task status updates 14:39:11 I1119 06:39:15.276967 168824832 sched.cpp:336] New master detected at master@10.0.49.4:61227 14:39:11 I1119 06:39:15.277015 168824832 sched.cpp:401] Authenticating with master master@10.0.49.4:61227 14:39:11 I1119 06:39:15.277029 168824832 sched.cpp:408] Using default CRAM-MD5 authenticatee 14:39:11 I1119 06:39:15.277178 167751680 authenticatee.cpp:121] Creating new client SASL connection 14:39:11 I1119 06:39:15.277346 169897984 master.cpp:9699] Authenticating scheduler-f91fa9d2-c57e-4118-b7ba-81f46d378a79@10.0.49.4:61227 14:39:11 I1119 06:39:15.277380 170434560 state.cpp:66] Recovering state from '/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/meta' 14:39:11 I1119 06:39:15.277441 168824832 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1512)@10.0.49.4:61227 14:39:11 I1119 06:39:15.277501 168288256 slave.cpp:6915] Finished recovering checkpointed state from '/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/meta', beginning agent recovery 14:39:11 I1119 06:39:15.277590 167751680 authenticator.cpp:98] Creating new server SASL connection 14:39:11 I1119 06:39:15.277578 169361408 task_status_update_manager.cpp:207] Recovering task status update manager 14:39:11 I1119 06:39:15.277705 170971136 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 14:39:11 I1119 06:39:15.277731 170971136 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 14:39:11 I1119 06:39:15.277789 170434560 authenticator.cpp:204] Received SASL authentication start 14:39:11 I1119 06:39:15.277865 170434560 authenticator.cpp:326] Authentication requires more steps 14:39:11 I1119 06:39:15.277918 168288256 containerizer.cpp:727] Recovering Mesos containers 14:39:11 I1119 06:39:15.278023 167751680 authenticatee.cpp:259] Received SASL authentication step 14:39:11 I1119 06:39:15.278050 168288256 containerizer.cpp:1053] Recovering isolators 14:39:11 I1119 06:39:15.278092 169361408 authenticator.cpp:232] Received SASL authentication step 14:39:11 I1119 06:39:15.278115 169361408 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'Jenkinss-Mac-mini.local' server FQDN: 'Jenkinss-Mac-mini.local' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 14:39:11 I1119 06:39:15.278144 169361408 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 14:39:11 I1119 06:39:15.278185 169361408 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 14:39:11 I1119 06:39:15.278205 169361408 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'Jenkinss-Mac-mini.local' server FQDN: 'Jenkinss-Mac-mini.local' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 14:39:11 I1119 06:39:15.278218 169361408 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 14:39:11 I1119 06:39:15.278228 169361408 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 14:39:11 I1119 06:39:15.278241 169361408 authenticator.cpp:318] Authentication success 14:39:11 I1119 06:39:15.278412 169897984 authenticatee.cpp:299] Authentication success 14:39:11 I1119 06:39:15.278461 168288256 master.cpp:9731] Successfully authenticated principal 'test-principal' at scheduler-f91fa9d2-c57e-4118-b7ba-81f46d378a79@10.0.49.4:61227 14:39:11 I1119 06:39:15.278484 170971136 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1512)@10.0.49.4:61227 14:39:11 I1119 06:39:15.278705 169361408 sched.cpp:513] Successfully authenticated with master master@10.0.49.4:61227 14:39:11 I1119 06:39:15.278726 169361408 sched.cpp:817] Sending SUBSCRIBE call to master@10.0.49.4:61227 14:39:11 I1119 06:39:15.278820 169361408 sched.cpp:850] Will retry registration in 180.347158ms if necessary 14:39:11 I1119 06:39:15.278838 169897984 containerizer.cpp:1092] Recovering provisioner 14:39:11 I1119 06:39:15.278961 167215104 master.cpp:2876] Received SUBSCRIBE call for framework 'default' at scheduler-f91fa9d2-c57e-4118-b7ba-81f46d378a79@10.0.49.4:61227 14:39:11 I1119 06:39:15.278980 167215104 master.cpp:2177] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' 14:39:11 I1119 06:39:15.279155 168288256 provisioner.cpp:494] Provisioner recovery complete 14:39:11 I1119 06:39:15.279166 167751680 master.cpp:2957] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] 14:39:11 I1119 06:39:15.279510 168824832 composing.cpp:339] Finished recovering all containerizers 14:39:11 I1119 06:39:15.279649 169361408 slave.cpp:7144] Recovering executors 14:39:11 I1119 06:39:15.279739 169361408 slave.cpp:7297] Finished recovery 14:39:11 I1119 06:39:15.280234 167751680 master.cpp:9929] Adding framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at scheduler-f91fa9d2-c57e-4118-b7ba-81f46d378a79@10.0.49.4:61227 with roles { } suppressed 14:39:11 I1119 06:39:15.280364 169361408 slave.cpp:1260] New master detected at master@10.0.49.4:61227 14:39:11 I1119 06:39:15.280418 169361408 slave.cpp:1325] Detecting new master 14:39:11 I1119 06:39:15.280503 170434560 task_status_update_manager.cpp:181] Pausing sending task status updates 14:39:11 I1119 06:39:15.280575 168824832 sched.cpp:744] Framework registered with be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.280624 169897984 hierarchical.cpp:304] Added framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.280637 168824832 sched.cpp:758] Scheduler::registered took 41698ns 14:39:11 I1119 06:39:15.280748 169897984 hierarchical.cpp:1566] Performed allocation for 0 agents in 39282ns 14:39:11 I1119 06:39:15.291321 170971136 slave.cpp:1352] Authenticating with master master@10.0.49.4:61227 14:39:11 I1119 06:39:15.291391 170971136 slave.cpp:1361] Using default CRAM-MD5 authenticatee 14:39:11 I1119 06:39:15.291515 167751680 authenticatee.cpp:121] Creating new client SASL connection 14:39:11 I1119 06:39:15.291652 170434560 master.cpp:9699] Authenticating slave(828)@10.0.49.4:61227 14:39:11 I1119 06:39:15.291715 168288256 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1513)@10.0.49.4:61227 14:39:11 I1119 06:39:15.291827 168824832 authenticator.cpp:98] Creating new server SASL connection 14:39:11 I1119 06:39:15.291947 169897984 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 14:39:11 I1119 06:39:15.291980 169897984 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 14:39:11 I1119 06:39:15.292027 167215104 authenticator.cpp:204] Received SASL authentication start 14:39:11 I1119 06:39:15.292095 167215104 authenticator.cpp:326] Authentication requires more steps 14:39:11 I1119 06:39:15.292170 169361408 authenticatee.cpp:259] Received SASL authentication step 14:39:11 I1119 06:39:15.292229 170971136 authenticator.cpp:232] Received SASL authentication step 14:39:11 I1119 06:39:15.292248 170971136 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'Jenkinss-Mac-mini.local' server FQDN: 'Jenkinss-Mac-mini.local' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 14:39:11 I1119 06:39:15.292261 170971136 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 14:39:11 I1119 06:39:15.292274 170971136 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 14:39:11 I1119 06:39:15.292284 170971136 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'Jenkinss-Mac-mini.local' server FQDN: 'Jenkinss-Mac-mini.local' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 14:39:11 I1119 06:39:15.292294 170971136 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 14:39:11 I1119 06:39:15.292302 170971136 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 14:39:11 I1119 06:39:15.292312 170971136 authenticator.cpp:318] Authentication success 14:39:11 I1119 06:39:15.292369 167751680 authenticatee.cpp:299] Authentication success 14:39:11 I1119 06:39:15.292409 170434560 master.cpp:9731] Successfully authenticated principal 'test-principal' at slave(828)@10.0.49.4:61227 14:39:11 I1119 06:39:15.292420 168288256 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1513)@10.0.49.4:61227 14:39:11 I1119 06:39:15.292557 168824832 slave.cpp:1452] Successfully authenticated with master master@10.0.49.4:61227 14:39:11 I1119 06:39:15.292769 168824832 slave.cpp:1883] Will retry registration in 1.614395ms if necessary 14:39:11 I1119 06:39:15.292850 170971136 master.cpp:6650] Received register agent message from slave(828)@10.0.49.4:61227 (Jenkinss-Mac-mini.local) 14:39:11 I1119 06:39:15.292981 170971136 master.cpp:3986] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal' 14:39:11 I1119 06:39:15.293256 169897984 master.cpp:6717] Authorized registration of agent at slave(828)@10.0.49.4:61227 (Jenkinss-Mac-mini.local) 14:39:11 I1119 06:39:15.293342 169897984 master.cpp:6832] Registering agent at slave(828)@10.0.49.4:61227 (Jenkinss-Mac-mini.local) with id be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 14:39:11 I1119 06:39:15.293634 167215104 registrar.cpp:487] Applied 1 operations in 140802ns; attempting to update the registry 14:39:11 I1119 06:39:15.293885 167215104 registrar.cpp:544] Successfully updated the registry in 221952ns 14:39:11 I1119 06:39:15.293956 168288256 master.cpp:6880] Admitted agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227 (Jenkinss-Mac-mini.local) 14:39:11 I1119 06:39:15.294142 168288256 master.cpp:6925] Registered agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227 (Jenkinss-Mac-mini.local) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] 14:39:11 I1119 06:39:15.294226 169897984 slave.cpp:1485] Registered with master master@10.0.49.4:61227; given agent ID be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 14:39:11 I1119 06:39:15.294286 170971136 task_status_update_manager.cpp:188] Resuming sending task status updates 14:39:11 I1119 06:39:15.294329 169361408 hierarchical.cpp:603] Added agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 (Jenkinss-Mac-mini.local) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {}) 14:39:11 I1119 06:39:15.294559 169897984 slave.cpp:1505] Checkpointing SlaveInfo to '/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/meta/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/slave.info' 14:39:11 I1119 06:39:15.294680 169361408 hierarchical.cpp:1566] Performed allocation for 1 agents in 268880ns 14:39:11 I1119 06:39:15.294847 170434560 master.cpp:9514] Sending offers [ be3714c6-f7ac-4dce-8791-7bddc37889d4-O0 ] to framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at scheduler-f91fa9d2-c57e-4118-b7ba-81f46d378a79@10.0.49.4:61227 14:39:11 I1119 06:39:15.295161 167215104 sched.cpp:914] Scheduler::resourceOffers took 101264ns 14:39:11 I1119 06:39:15.295339 169897984 slave.cpp:1554] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"pIFlAHOPSGSAkO4feS0sAw=="},"slave_id":{"value":"be3714c6-f7ac-4dce-8791-7bddc37889d4-S0"},"update_oversubscribed_resources":false} 14:39:11 I1119 06:39:15.295725 168288256 master.cpp:7984] Ignoring update on agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227 (Jenkinss-Mac-mini.local) as it reports no changes 14:39:11 I1119 06:39:15.296494 169897984 process.cpp:3588] Handling HTTP event for process 'slave(828)' with path: '/slave(828)/api/v1' 14:39:11 I1119 06:39:15.297157 170434560 http.cpp:1182] HTTP POST for /slave(828)/api/v1 from 10.0.49.4:63781 14:39:11 I1119 06:39:15.297356 170434560 http.cpp:1454] Processing GET_FRAMEWORKS call 14:39:11 I1119 06:39:15.298992 168824832 master.cpp:11513] Removing offer be3714c6-f7ac-4dce-8791-7bddc37889d4-O0 14:39:11 I1119 06:39:15.299257 168824832 master.cpp:4511] Processing ACCEPT call for offers: [ be3714c6-f7ac-4dce-8791-7bddc37889d4-O0 ] on agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227 (Jenkinss-Mac-mini.local) for framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at scheduler-f91fa9d2-c57e-4118-b7ba-81f46d378a79@10.0.49.4:61227 14:39:11 I1119 06:39:15.299327 168824832 master.cpp:3563] Authorizing framework principal 'test-principal' to launch task 1 14:39:11 I1119 06:39:15.300367 170434560 master.cpp:4088] Adding task 1 with resources cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at scheduler-f91fa9d2-c57e-4118-b7ba-81f46d378a79@10.0.49.4:61227 on agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227 (Jenkinss-Mac-mini.local) 14:39:11 I1119 06:39:15.300609 170434560 master.cpp:5483] Launching task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at scheduler-f91fa9d2-c57e-4118-b7ba-81f46d378a79@10.0.49.4:61227 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] on agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227 (Jenkinss-Mac-mini.local) on new executor 14:39:11 I1119 06:39:15.301375 167215104 slave.cpp:2020] Got assigned task '1' for framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.302006 167215104 slave.cpp:2394] Authorizing task '1' for framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.302045 167215104 slave.cpp:8472] Authorizing framework principal 'test-principal' to launch task 1 14:39:11 I1119 06:39:15.302819 167215104 slave.cpp:2837] Launching task '1' for framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.302872 167215104 paths.cpp:752] Creating sandbox '/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10' for user 'jenkins' 14:39:11 I1119 06:39:15.303869 167215104 slave.cpp:9000] Launching executor '1' of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"}] in work directory '/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10' 14:39:11 I1119 06:39:15.304333 167215104 slave.cpp:3034] Queued task '1' for executor '1' of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.304420 167215104 slave.cpp:994] Successfully attached '/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10' to virtual path '/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/latest' 14:39:11 I1119 06:39:15.304605 167215104 slave.cpp:3515] Launching container 28632eb3-e3fb-41cf-8698-1353f9ccfa10 for executor '1' of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.304941 167215104 slave.cpp:994] Successfully attached '/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10' to virtual path '/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/latest' 14:39:11 I1119 06:39:15.304965 167215104 slave.cpp:994] Successfully attached '/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10' to virtual path '/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10' 14:39:11 I1119 06:39:15.305202 169361408 containerizer.cpp:1288] Starting container 28632eb3-e3fb-41cf-8698-1353f9ccfa10 14:39:11 I1119 06:39:15.306092 169361408 containerizer.cpp:1454] Checkpointed ContainerConfig at '/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/containers/28632eb3-e3fb-41cf-8698-1353f9ccfa10/config' 14:39:11 I1119 06:39:15.306118 169361408 containerizer.cpp:3130] Transitioning the state of container 28632eb3-e3fb-41cf-8698-1353f9ccfa10 from PROVISIONING to PREPARING 14:39:11 I1119 06:39:15.307767 169897984 containerizer.cpp:1947] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=/Users/jenkins/workspace/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mac/mesos/build/src"],"shell":false,"value":"/Users/jenkins/workspace/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mac/mesos/build/src/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"10.0.49.4:61227"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiIyODYzMmViMy1lM2ZiLTQxY2YtODY5OC0xMzUzZjljY2ZhMTAiLCJlaWQiOiIxIiwiZmlkIjoiYmUzNzE0YzYtZjdhYy00ZGNlLTg3OTEtN2JkZGMzNzg4OWQ0LTAwMDAifQ.OoSLOnlVGd8hsijTazWpBeFFobk0XKOq8-LuL4l2s2c"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"1"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"be3714c6-f7ac-4dce-8791-7bddc37889d4-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"be3714c6-f7ac-4dce-8791-7bddc37889d4-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(828)@10.0.49.4:61227"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10"}]},"task_environment":{},"user":"jenkins","working_directory":"/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10"}" --pipe_read="24" --pipe_write="28" --runtime_directory="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/containers/28632eb3-e3fb-41cf-8698-1353f9ccfa10"' 14:39:11 I1119 06:39:15.309439 169897984 launcher.cpp:145] Forked child with pid '71895' for container '28632eb3-e3fb-41cf-8698-1353f9ccfa10' 14:39:11 I1119 06:39:15.310206 169897984 containerizer.cpp:3130] Transitioning the state of container 28632eb3-e3fb-41cf-8698-1353f9ccfa10 from PREPARING to ISOLATING 14:39:11 I1119 06:39:15.312588 169897984 containerizer.cpp:3130] Transitioning the state of container 28632eb3-e3fb-41cf-8698-1353f9ccfa10 from ISOLATING to FETCHING 14:39:11 I1119 06:39:15.312872 170434560 fetcher.cpp:369] Starting to fetch URIs for container: 28632eb3-e3fb-41cf-8698-1353f9ccfa10, directory: /var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10 14:39:11 I1119 06:39:15.313565 167751680 containerizer.cpp:3130] Transitioning the state of container 28632eb3-e3fb-41cf-8698-1353f9ccfa10 from FETCHING to RUNNING 14:39:11 [warn] kq_init: detected broken kqueue; not using.: Undefined error: 0 14:39:11 I1119 06:39:15.474073 151658496 exec.cpp:162] Version: 1.8.0 14:39:11 I1119 06:39:15.477310 167751680 slave.cpp:4809] Got registration for executor '1' of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 from executor(1)@10.0.49.4:63782 14:39:11 I1119 06:39:15.478510 168288256 slave.cpp:3247] Sending queued task '1' to executor '1' of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 at executor(1)@10.0.49.4:63782 14:39:11 I1119 06:39:15.478849 149512192 exec.cpp:236] Executor registered on agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 14:39:11 I1119 06:39:15.485213 148975616 executor.cpp:184] Received SUBSCRIBED event 14:39:11 I1119 06:39:15.485697 148975616 executor.cpp:188] Subscribed executor on Jenkinss-Mac-mini.local 14:39:11 I1119 06:39:15.485786 148975616 executor.cpp:184] Received LAUNCH event 14:39:11 I1119 06:39:15.491688 148975616 executor.cpp:687] Starting task 1 14:39:11 I1119 06:39:15.497985 167215104 slave.cpp:5275] Handling status update TASK_STARTING (Status UUID: aca86396-e493-4a95-9bd3-d723058e9da7) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 from executor(1)@10.0.49.4:63782 14:39:11 I1119 06:39:15.498713 148975616 executor.cpp:502] Running '/Users/jenkins/workspace/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mac/mesos/build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>' 14:39:11 I1119 06:39:15.498822 167751680 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: aca86396-e493-4a95-9bd3-d723058e9da7) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.498853 167751680 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.499197 167751680 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: aca86396-e493-4a95-9bd3-d723058e9da7) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 to the agent 14:39:11 I1119 06:39:15.499266 169897984 slave.cpp:5767] Forwarding the update TASK_STARTING (Status UUID: aca86396-e493-4a95-9bd3-d723058e9da7) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 to master@10.0.49.4:61227 14:39:11 I1119 06:39:15.499434 169897984 slave.cpp:5660] Task status update manager successfully handled status update TASK_STARTING (Status UUID: aca86396-e493-4a95-9bd3-d723058e9da7) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.499503 169897984 slave.cpp:5676] Sending acknowledgement for status update TASK_STARTING (Status UUID: aca86396-e493-4a95-9bd3-d723058e9da7) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 to executor(1)@10.0.49.4:63782 14:39:11 I1119 06:39:15.499511 168288256 master.cpp:8420] Status update TASK_STARTING (Status UUID: aca86396-e493-4a95-9bd3-d723058e9da7) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 from agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227 (Jenkinss-Mac-mini.local) 14:39:11 I1119 06:39:15.499544 168288256 master.cpp:8477] Forwarding status update TASK_STARTING (Status UUID: aca86396-e493-4a95-9bd3-d723058e9da7) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.499650 168288256 master.cpp:10978] Updating the state of task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING) 14:39:11 I1119 06:39:15.499884 167215104 sched.cpp:1022] Scheduler::statusUpdate took 108414ns 14:39:11 I1119 06:39:15.500064 170434560 master.cpp:6286] Processing ACKNOWLEDGE call for status aca86396-e493-4a95-9bd3-d723058e9da7 for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at scheduler-f91fa9d2-c57e-4118-b7ba-81f46d378a79@10.0.49.4:61227 on agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 14:39:11 I1119 06:39:15.500166 148975616 executor.cpp:702] Forked command at 71923 14:39:11 I1119 06:39:15.500257 169897984 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: aca86396-e493-4a95-9bd3-d723058e9da7) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.500407 170971136 slave.cpp:4511] Task status update manager successfully handled status update acknowledgement (UUID: aca86396-e493-4a95-9bd3-d723058e9da7) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.507848 168824832 slave.cpp:5275] Handling status update TASK_RUNNING (Status UUID: a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 from executor(1)@10.0.49.4:63782 14:39:11 I1119 06:39:15.508744 169897984 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.508831 169897984 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 to the agent 14:39:11 I1119 06:39:15.509007 168288256 slave.cpp:5767] Forwarding the update TASK_RUNNING (Status UUID: a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 to master@10.0.49.4:61227 14:39:11 I1119 06:39:15.509145 168288256 slave.cpp:5660] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.509188 168288256 slave.cpp:5676] Sending acknowledgement for status update TASK_RUNNING (Status UUID: a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 to executor(1)@10.0.49.4:63782 14:39:11 I1119 06:39:15.509207 170971136 master.cpp:8420] Status update TASK_RUNNING (Status UUID: a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 from agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227 (Jenkinss-Mac-mini.local) 14:39:11 I1119 06:39:15.509243 170971136 master.cpp:8477] Forwarding status update TASK_RUNNING (Status UUID: a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.509382 170971136 master.cpp:10978] Updating the state of task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING) 14:39:11 I1119 06:39:15.509624 168824832 sched.cpp:1022] Scheduler::statusUpdate took 107500ns 14:39:11 I1119 06:39:15.509821 169361408 master.cpp:6286] Processing ACKNOWLEDGE call for status a49a359c-1cb8-4551-8df3-bc28ac2b7a2a for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at scheduler-f91fa9d2-c57e-4118-b7ba-81f46d378a79@10.0.49.4:61227 on agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 14:39:11 I1119 06:39:15.510013 168288256 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.510170 167751680 slave.cpp:4511] Task status update manager successfully handled status update acknowledgement (UUID: a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.511095 169897984 process.cpp:3588] Handling HTTP event for process 'slave(828)' with path: '/slave(828)/api/v1' 14:39:11 I1119 06:39:15.511780 168288256 http.cpp:1182] HTTP POST for /slave(828)/api/v1 from 10.0.49.4:63785 14:39:11 I1119 06:39:15.511982 168288256 http.cpp:1454] Processing GET_FRAMEWORKS call 14:39:11 I1119 06:39:15.513320 2668864320 sched.cpp:2008] Asked to stop the driver 14:39:11 I1119 06:39:15.513387 170434560 sched.cpp:1184] Stopping framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.513556 167215104 master.cpp:10231] Processing TEARDOWN call for framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at scheduler-f91fa9d2-c57e-4118-b7ba-81f46d378a79@10.0.49.4:61227 14:39:11 I1119 06:39:15.513588 167215104 master.cpp:10243] Removing framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at scheduler-f91fa9d2-c57e-4118-b7ba-81f46d378a79@10.0.49.4:61227 14:39:11 I1119 06:39:15.513605 167215104 master.cpp:3252] Deactivating framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at scheduler-f91fa9d2-c57e-4118-b7ba-81f46d378a79@10.0.49.4:61227 14:39:11 I1119 06:39:15.513739 167215104 master.cpp:10978] Updating the state of task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED) 14:39:11 I1119 06:39:15.513789 167751680 hierarchical.cpp:418] Deactivated framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.513829 168824832 slave.cpp:3902] Asked to shut down framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 by master@10.0.49.4:61227 14:39:11 I1119 06:39:15.513851 168824832 slave.cpp:3927] Shutting down framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.513883 168824832 slave.cpp:6646] Shutting down executor '1' of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 at executor(1)@10.0.49.4:63782 14:39:11 I1119 06:39:15.514106 167215104 master.cpp:11076] Removing task 1 with resources cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 on agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227 (Jenkinss-Mac-mini.local) 14:39:11 I1119 06:39:15.514303 169361408 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 be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 from framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.514572 169897984 hierarchical.cpp:357] Removed framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:11 I1119 06:39:15.514663 147902464 exec.cpp:445] Executor asked to shutdown 14:39:11 I1119 06:39:15.514859 149512192 executor.cpp:184] Received SHUTDOWN event 14:39:11 I1119 06:39:15.514885 149512192 executor.cpp:805] Shutting down 14:39:11 I1119 06:39:15.514914 149512192 executor.cpp:918] Sending SIGTERM to process tree at pid 71923 14:39:11 I1119 06:39:15.552628 149512192 executor.cpp:931] Sent SIGTERM to the following process trees: 14:39:11 [ 14:39:11 -+- 71923 /bin/sh /Users/jenkins/workspace/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mac/mesos/build/src/mesos-containerizer launch --help=false --launch_info={"command":{"shell":true,"value":"sleep 1000"},"environment":{"variables":[{"name":"PATH","type":"VALUE","value":"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"},{"name":"PWD","type":"VALUE","value":"/private/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(828)@10.0.49.4:61227"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"be3714c6-f7ac-4dce-8791-7bddc37889d4-0000"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"1"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiIyODYzMmViMy1lM2ZiLTQxY2YtODY5OC0xMzUzZjljY2ZhMTAiLCJlaWQiOiIxIiwiZmlkIjoiYmUzNzE0YzYtZjdhYy00ZGNlLTg3OTEtN2JkZGMzNzg4OWQ0LTAwMDAifQ.OoSLOnlVGd8hsijTazWpBeFFobk0XKOq8-LuL4l2s2c"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"be3714c6-f7ac-4dce-8791-7bddc37889d4-S0"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"SHLVL","type":"VALUE","value":"0"},{"name":"DUALCASE","type":"VALUE","value":"1"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"10.0.49.4:61227"},{"name":"DYLD_LIBRARY_PATH","type":"VALUE","value":"/Users/jenkins/workspace/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mac/mesos/build/src/.libs"},{"name":"__CF_USER_TEXT_ENCODING","type":"VALUE","value":"0x1F5:0x0:0x0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10"},{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"BIN_SH","type":"VALUE","value":"xpg4"}]}} 14:39:11 \--- 71934 (sh) 14:39:11 ] 14:39:11 I1119 06:39:15.552690 149512192 executor.cpp:935] Scheduling escalation to SIGKILL in 3secs from now 14:39:11 I1119 06:39:15.570111 151121920 executor.cpp:1003] Command terminated with signal Terminated: 15 (pid: 71923) 14:39:11 I1119 06:39:15.576234 168824832 slave.cpp:5275] Handling status update TASK_KILLED (Status UUID: c5d92cee-03c1-45ce-8cb0-81d0dfc968d8) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 from executor(1)@10.0.49.4:63782 14:39:11 W1119 06:39:15.576290 168824832 slave.cpp:5344] Ignoring status update TASK_KILLED (Status UUID: c5d92cee-03c1-45ce-8cb0-81d0dfc968d8) for task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 for terminating framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 14:39:51 I1119 06:39:51.104415 167215104 slave.cpp:6719] Killing executor '1' of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 at executor(1)@10.0.49.4:63782 14:39:51 I1119 06:39:51.106272 168288256 slave.cpp:5899] Got exited event for executor(1)@10.0.49.4:63782 14:39:51 ../../src/tests/api_tests.cpp:5500: Failure 14:39:51 Failed to wait 15secs for executorTerminated 14:39:51 I1119 06:39:51.106459 170434560 containerizer.cpp:2463] Destroying container 28632eb3-e3fb-41cf-8698-1353f9ccfa10 in RUNNING state 14:39:51 I1119 06:39:51.106482 170434560 containerizer.cpp:3130] Transitioning the state of container 28632eb3-e3fb-41cf-8698-1353f9ccfa10 from RUNNING to DESTROYING 14:39:51 I1119 06:39:51.106822 170434560 launcher.cpp:161] Asked to destroy container 28632eb3-e3fb-41cf-8698-1353f9ccfa10 14:39:51 I1119 06:39:51.107393 2668864320 slave.cpp:915] Agent terminating 14:39:51 I1119 06:39:51.107439 2668864320 slave.cpp:3902] Asked to shut down framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 by @0.0.0.0:0 14:39:51 W1119 06:39:51.107461 2668864320 slave.cpp:3923] Ignoring shutdown framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 because it is terminating 14:39:51 I1119 06:39:51.165649 168824832 master.cpp:1273] Agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227 (Jenkinss-Mac-mini.local) disconnected 14:39:51 I1119 06:39:51.165710 168824832 master.cpp:3289] Disconnecting agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227 (Jenkinss-Mac-mini.local) 14:39:51 I1119 06:39:51.165760 168824832 master.cpp:3308] Deactivating agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227 (Jenkinss-Mac-mini.local) 14:39:51 I1119 06:39:51.165907 169361408 hierarchical.cpp:801] Agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 deactivated 14:39:51 I1119 06:39:51.205538 167751680 containerizer.cpp:2969] Container 28632eb3-e3fb-41cf-8698-1353f9ccfa10 has exited 14:39:51 I1119 06:39:51.206760 168824832 provisioner.cpp:597] Ignoring destroy request for unknown container 28632eb3-e3fb-41cf-8698-1353f9ccfa10 14:39:51 I1119 06:39:51.214574 2668864320 master.cpp:1115] Master terminating 14:39:51 I1119 06:39:51.215334 168288256 hierarchical.cpp:643] Removed agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 14:39:51 ../../3rdparty/libprocess/include/process/gmock.hpp:545: Failure 14:39:51 Actual function call count doesn't match EXPECT_CALL(filter->mock, filter(pid, testing::A<const DispatchEvent&>()))... 14:39:51 Expected args: dispatch matcher 16-byte object <59-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00> 14:39:51 Expected: to be called once 14:39:51 Actual: never called - unsatisfied and active 14:39:51 [ FAILED ] ContentType/AgentAPITest.GetFrameworks/1, where GetParam() = application/json (35956 ms)