See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4486/display/redirect?page=changes>
Changes: [alexr] Fixed a task status update race in default executor tests. [alexr] Renamed `TaskStatusEq()` to `TaskStatusTaskIdEq()`. ------------------------------------------ [...truncated 18.56 MB...] 3: I1121 18:16:14.073251 18311 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1121 18:16:14.075753 18305 state.cpp:64] Recovering state from '/tmp/MetricsTest_AgentAuthorizationEnabled_OONfIL/meta' 3: I1121 18:16:14.075892 18318 slave.cpp:883] Agent terminating 3: I1121 18:16:14.081837 18301 master.cpp:1153] Master terminating 3: [ OK ] MetricsTest.AgentAuthorizationEnabled (47 ms) 3: [----------] 4 tests from MetricsTest (140 ms total) 3: 3: [----------] 26 tests from ModuleTest 3: [ RUN ] ModuleTest.ExampleModuleLoadTest 3: [ OK ] ModuleTest.ExampleModuleLoadTest (1 ms) 3: [ RUN ] ModuleTest.ModulesDirTest 3: I1121 18:16:14.092104 18300 manager.cpp:370] Processing module manifest from '/tmp/JLEtu4/modules_dir/default_module.json' 3: I1121 18:16:14.092639 18300 manager.cpp:370] Processing module manifest from '/tmp/JLEtu4/modules_dir/dup_default_module.json' 3: I1121 18:16:14.092996 18300 manager.cpp:370] Processing module manifest from '/tmp/JLEtu4/modules_dir/extra_module.json' 3: [ OK ] ModuleTest.ModulesDirTest (3 ms) 3: [ RUN ] ModuleTest.ParameterWithoutValue 3: [ OK ] ModuleTest.ParameterWithoutValue (1 ms) 3: [ RUN ] ModuleTest.ParameterWithInvalidValue 3: [ OK ] ModuleTest.ParameterWithInvalidValue (0 ms) 3: [ RUN ] ModuleTest.ParameterWithoutKey 3: [ OK ] ModuleTest.ParameterWithoutKey (1 ms) 3: [ RUN ] ModuleTest.ParameterWithInvalidKey 3: [ OK ] ModuleTest.ParameterWithInvalidKey (0 ms) 3: [ RUN ] ModuleTest.ValidParameters 3: [ OK ] ModuleTest.ValidParameters (0 ms) 3: [ RUN ] ModuleTest.OverrideJson 3: [ OK ] ModuleTest.OverrideJson (1 ms) 3: [ RUN ] ModuleTest.JsonParseTest 3: [ OK ] ModuleTest.JsonParseTest (1 ms) 3: [ RUN ] ModuleTest.ExampleModuleUnloadTest 3: [ OK ] ModuleTest.ExampleModuleUnloadTest (0 ms) 3: [ RUN ] ModuleTest.InvalidModuleKind 3: [ OK ] ModuleTest.InvalidModuleKind (0 ms) 3: [ RUN ] ModuleTest.ModuleKindMismatch 3: [ OK ] ModuleTest.ModuleKindMismatch (1 ms) 3: [ RUN ] ModuleTest.AuthorInfoTest 3: [ OK ] ModuleTest.AuthorInfoTest (0 ms) 3: [ RUN ] ModuleTest.LibraryNameWithoutExtension 3: [ OK ] ModuleTest.LibraryNameWithoutExtension (0 ms) 3: [ RUN ] ModuleTest.EmptyLibraryFilename 3: [ OK ] ModuleTest.EmptyLibraryFilename (1 ms) 3: [ RUN ] ModuleTest.EmptyModuleName 3: [ OK ] ModuleTest.EmptyModuleName (0 ms) 3: [ RUN ] ModuleTest.UnknownLibraryTest 3: [ OK ] ModuleTest.UnknownLibraryTest (0 ms) 3: [ RUN ] ModuleTest.UnknownModuleTest 3: [ OK ] ModuleTest.UnknownModuleTest (1 ms) 3: [ RUN ] ModuleTest.UnknownModuleInstantiationTest 3: [ OK ] ModuleTest.UnknownModuleInstantiationTest (0 ms) 3: [ RUN ] ModuleTest.NonModuleLibrary 3: [ OK ] ModuleTest.NonModuleLibrary (1 ms) 3: [ RUN ] ModuleTest.LoadSameModuleTwice 3: [ OK ] ModuleTest.LoadSameModuleTwice (0 ms) 3: [ RUN ] ModuleTest.DuplicateModulesWithDifferentParameters 3: [ OK ] ModuleTest.DuplicateModulesWithDifferentParameters (1 ms) 3: [ RUN ] ModuleTest.DuplicateModuleInDifferentLibraries 3: [ OK ] ModuleTest.DuplicateModuleInDifferentLibraries (0 ms) 3: [ RUN ] ModuleTest.DifferentApiVersion 3: [ OK ] ModuleTest.DifferentApiVersion (1 ms) 3: [ RUN ] ModuleTest.NewerModuleLibrary 3: [ OK ] ModuleTest.NewerModuleLibrary (0 ms) 3: [ RUN ] ModuleTest.OlderModuleLibrary 3: [ OK ] ModuleTest.OlderModuleLibrary (0 ms) 3: [----------] 26 tests from ModuleTest (14 ms total) 3: 3: [----------] 14 tests from OversubscriptionTest 3: [ RUN ] OversubscriptionTest.FetchResourceUsage 3: I1121 18:16:14.107127 18300 cluster.cpp:162] Creating default 'local' authorizer 3: I1121 18:16:14.110922 18324 master.cpp:448] Master 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3 (849074e36b7e) started on 172.17.0.4:36588 3: I1121 18:16:14.110992 18324 master.cpp:450] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/0njg6W/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" --port="5050" --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" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/0njg6W/master" --zk_session_timeout="10secs" 3: I1121 18:16:14.111383 18324 master.cpp:499] Master only allowing authenticated frameworks to register 3: I1121 18:16:14.111389 18324 master.cpp:505] Master only allowing authenticated agents to register 3: I1121 18:16:14.111393 18324 master.cpp:511] Master only allowing authenticated HTTP frameworks to register 3: I1121 18:16:14.111397 18324 credentials.hpp:37] Loading credentials for authentication from '/tmp/0njg6W/credentials' 3: I1121 18:16:14.111739 18324 master.cpp:555] Using default 'crammd5' authenticator 3: I1121 18:16:14.111938 18324 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' 3: I1121 18:16:14.112104 18324 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' 3: I1121 18:16:14.112239 18324 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' 3: I1121 18:16:14.112339 18324 master.cpp:634] Authorization enabled 3: I1121 18:16:14.112494 18309 hierarchical.cpp:173] Initialized hierarchical allocator process 3: I1121 18:16:14.112524 18301 whitelist_watcher.cpp:77] No whitelist given 3: I1121 18:16:14.115977 18318 master.cpp:2215] Elected as the leading master! 3: I1121 18:16:14.116003 18318 master.cpp:1695] Recovering from registrar 3: I1121 18:16:14.116138 18319 registrar.cpp:347] Recovering registrar 3: I1121 18:16:14.116780 18319 registrar.cpp:391] Successfully fetched the registry (0B) in 609024ns 3: I1121 18:16:14.116911 18319 registrar.cpp:495] Applied 1 operations in 53840ns; attempting to update the registry 3: I1121 18:16:14.117456 18319 registrar.cpp:552] Successfully updated the registry in 486912ns 3: I1121 18:16:14.117571 18319 registrar.cpp:424] Successfully recovered registrar 3: I1121 18:16:14.117980 18308 master.cpp:1808] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register 3: I1121 18:16:14.118014 18315 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover 3: W1121 18:16:14.125239 18300 process.cpp:2756] Attempted to spawn already running process [email protected]:36588 3: I1121 18:16:14.125635 18300 cluster.cpp:448] Creating default 'local' authorizer 3: I1121 18:16:14.128454 18318 slave.cpp:262] Mesos agent started on (452)@172.17.0.4:36588 3: I1121 18:16:14.128489 18318 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/OversubscriptionTest_FetchResourceUsage_FTD9aP/store/appc" --authenticate_http_executors="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --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/OversubscriptionTest_FetchResourceUsage_FTD9aP/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io"; --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/OversubscriptionTest_FetchResourceUsage_FTD9aP/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_secret_key="/tmp/OversubscriptionTest_FetchResourceUsage_FTD9aP/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/OversubscriptionTest_FetchResourceUsage_FTD9aP/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/OversubscriptionTest_FetchResourceUsage_FTD9aP/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/OversubscriptionTest_FetchResourceUsage_FTD9aP" --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/OversubscriptionTest_FetchResourceUsage_sw3G8n" --zk_session_timeout="10secs" 3: I1121 18:16:14.128906 18318 credentials.hpp:86] Loading credential for authentication from '/tmp/OversubscriptionTest_FetchResourceUsage_FTD9aP/credential' 3: I1121 18:16:14.129150 18318 slave.cpp:295] Agent using credential for: test-principal 3: I1121 18:16:14.129168 18318 credentials.hpp:37] Loading credentials for authentication from '/tmp/OversubscriptionTest_FetchResourceUsage_FTD9aP/http_credentials' 3: I1121 18:16:14.129473 18318 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor' 3: W1121 18:16:14.129513 18300 process.cpp:2756] Attempted to spawn already running process [email protected]:36588 3: I1121 18:16:14.129642 18318 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor' 3: I1121 18:16:14.129882 18318 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1121 18:16:14.129978 18318 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1121 18:16:14.130198 18318 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1121 18:16:14.130292 18318 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1121 18:16:14.130672 18300 sched.cpp:232] Version: 1.5.0 3: I1121 18:16:14.131342 18322 sched.cpp:336] New master detected at [email protected]:36588 3: I1121 18:16:14.131458 18322 sched.cpp:396] Authenticating with master [email protected]:36588 3: I1121 18:16:14.131479 18322 sched.cpp:403] Using default CRAM-MD5 authenticatee 3: I1121 18:16:14.131872 18306 authenticatee.cpp:121] Creating new client SASL connection 3: I1121 18:16:14.132197 18307 master.cpp:8306] Authenticating [email protected]:36588 3: I1121 18:16:14.132045 18318 slave.cpp:593] 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"}] 3: I1121 18:16:14.132279 18318 slave.cpp:601] Agent attributes: [ ] 3: I1121 18:16:14.132294 18318 slave.cpp:610] Agent hostname: 849074e36b7e 3: I1121 18:16:14.132305 18303 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(938)@172.17.0.4:36588 3: I1121 18:16:14.132493 18320 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1121 18:16:14.132542 18314 authenticator.cpp:98] Creating new server SASL connection 3: I1121 18:16:14.132748 18316 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1121 18:16:14.132771 18316 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1121 18:16:14.132870 18319 authenticator.cpp:204] Received SASL authentication start 3: I1121 18:16:14.132920 18319 authenticator.cpp:326] Authentication requires more steps 3: I1121 18:16:14.133014 18313 authenticatee.cpp:259] Received SASL authentication step 3: I1121 18:16:14.133124 18315 authenticator.cpp:232] Received SASL authentication step 3: I1121 18:16:14.133150 18315 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '849074e36b7e' server FQDN: '849074e36b7e' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1121 18:16:14.133159 18315 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1121 18:16:14.133204 18315 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1121 18:16:14.133222 18315 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '849074e36b7e' server FQDN: '849074e36b7e' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1121 18:16:14.133229 18315 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1121 18:16:14.133234 18315 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1121 18:16:14.133246 18315 authenticator.cpp:318] Authentication success 3: I1121 18:16:14.133342 18301 authenticatee.cpp:299] Authentication success 3: I1121 18:16:14.133429 18302 master.cpp:8336] Successfully authenticated principal 'test-principal' at [email protected]:36588 3: I1121 18:16:14.133565 18309 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(938)@172.17.0.4:36588 3: I1121 18:16:14.133910 18301 sched.cpp:502] Successfully authenticated with master [email protected]:36588 3: I1121 18:16:14.133952 18301 sched.cpp:824] Sending SUBSCRIBE call to [email protected]:36588 3: I1121 18:16:14.134130 18301 sched.cpp:857] Will retry registration in 780.72162ms if necessary 3: I1121 18:16:14.134371 18317 master.cpp:2963] Received SUBSCRIBE call for framework 'default' at [email protected]:36588 3: I1121 18:16:14.134402 18317 master.cpp:2280] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' 3: I1121 18:16:14.134626 18308 state.cpp:64] Recovering state from '/tmp/OversubscriptionTest_FetchResourceUsage_sw3G8n/meta' 3: I1121 18:16:14.135004 18321 task_status_update_manager.cpp:207] Recovering task status update manager 3: I1121 18:16:14.135038 18318 master.cpp:3043] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ] 3: I1121 18:16:14.135365 18320 slave.cpp:6443] Finished recovery 3: I1121 18:16:14.135726 18318 sched.cpp:751] Framework registered with 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 3: I1121 18:16:14.135769 18318 sched.cpp:765] Scheduler::registered took 29343ns 3: I1121 18:16:14.135921 18303 hierarchical.cpp:306] Added framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 3: I1121 18:16:14.136160 18303 hierarchical.cpp:1457] Performed allocation for 0 agents in 108721ns 3: I1121 18:16:14.136174 18312 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1121 18:16:14.136171 18320 slave.cpp:1007] New master detected at [email protected]:36588 3: I1121 18:16:14.136301 18320 slave.cpp:1042] Detecting new master 3: I1121 18:16:14.139782 18315 slave.cpp:1069] Authenticating with master [email protected]:36588 3: I1121 18:16:14.139925 18315 slave.cpp:1078] Using default CRAM-MD5 authenticatee 3: I1121 18:16:14.140301 18309 authenticatee.cpp:121] Creating new client SASL connection 3: I1121 18:16:14.140746 18324 master.cpp:8306] Authenticating slave(452)@172.17.0.4:36588 3: I1121 18:16:14.140867 18310 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(939)@172.17.0.4:36588 3: I1121 18:16:14.141180 18301 authenticator.cpp:98] Creating new server SASL connection 3: I1121 18:16:14.141438 18317 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1121 18:16:14.141466 18317 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1121 18:16:14.141600 18311 authenticator.cpp:204] Received SASL authentication start 3: I1121 18:16:14.141651 18311 authenticator.cpp:326] Authentication requires more steps 3: I1121 18:16:14.141757 18304 authenticatee.cpp:259] Received SASL authentication step 3: I1121 18:16:14.141870 18305 authenticator.cpp:232] Received SASL authentication step 3: I1121 18:16:14.141896 18305 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '849074e36b7e' server FQDN: '849074e36b7e' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1121 18:16:14.141907 18305 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1121 18:16:14.141947 18305 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1121 18:16:14.141960 18305 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '849074e36b7e' server FQDN: '849074e36b7e' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1121 18:16:14.141966 18305 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1121 18:16:14.141970 18305 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1121 18:16:14.141983 18305 authenticator.cpp:318] Authentication success 3: I1121 18:16:14.142076 18321 authenticatee.cpp:299] Authentication success 3: I1121 18:16:14.142128 18308 master.cpp:8336] Successfully authenticated principal 'test-principal' at slave(452)@172.17.0.4:36588 3: I1121 18:16:14.142194 18307 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(939)@172.17.0.4:36588 3: I1121 18:16:14.142477 18321 slave.cpp:1161] Successfully authenticated with master [email protected]:36588 3: I1121 18:16:14.142814 18321 slave.cpp:1682] Will retry registration in 18.535819ms if necessary 3: I1121 18:16:14.143128 18318 master.cpp:6036] Received register agent message from slave(452)@172.17.0.4:36588 (849074e36b7e) 3: I1121 18:16:14.143194 18318 master.cpp:3872] Authorizing agent with principal 'test-principal' 3: I1121 18:16:14.143760 18313 master.cpp:6098] Authorized registration of agent at slave(452)@172.17.0.4:36588 (849074e36b7e) 3: I1121 18:16:14.143905 18313 master.cpp:6191] Registering agent at slave(452)@172.17.0.4:36588 (849074e36b7e) with id 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0 3: I1121 18:16:14.144356 18303 registrar.cpp:495] Applied 1 operations in 101817ns; attempting to update the registry 3: I1121 18:16:14.145133 18303 registrar.cpp:552] Successfully updated the registry in 689920ns 3: I1121 18:16:14.145423 18303 master.cpp:6240] Admitted agent 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0 at slave(452)@172.17.0.4:36588 (849074e36b7e) 3: I1121 18:16:14.146422 18324 slave.cpp:1207] Registered with master [email protected]:36588; given agent ID 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0 3: I1121 18:16:14.146571 18317 task_status_update_manager.cpp:188] Resuming sending task status updates 3: I1121 18:16:14.146282 18303 master.cpp:6273] Registered agent 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0 at slave(452)@172.17.0.4:36588 (849074e36b7e) with [{"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"}] 3: I1121 18:16:14.146730 18312 hierarchical.cpp:600] Added agent 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0 (849074e36b7e) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {}) 3: I1121 18:16:14.146806 18324 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/OversubscriptionTest_FetchResourceUsage_sw3G8n/meta/slaves/5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0/slave.info' 3: I1121 18:16:14.148378 18312 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.476423ms 3: I1121 18:16:14.148885 18311 master.cpp:8136] Sending 1 offers to framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 (default) at [email protected]:36588 3: I1121 18:16:14.149449 18304 sched.cpp:921] Scheduler::resourceOffers took 116522ns 3: I1121 18:16:14.152304 18321 master.cpp:10045] Removing offer 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-O0 3: I1121 18:16:14.152529 18321 master.cpp:4230] Processing ACCEPT call for offers: [ 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-O0 ] on agent 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0 at slave(452)@172.17.0.4:36588 (849074e36b7e) for framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 (default) at [email protected]:36588 3: I1121 18:16:14.152698 18321 master.cpp:3599] Authorizing framework principal 'test-principal' to launch task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc 3: W1121 18:16:14.155411 18321 validation.cpp:1391] Executor 'exit 1' for task '8c9b137b-31dd-465a-baf1-f6b48bf33dfc' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases. 3: W1121 18:16:14.155457 18321 validation.cpp:1403] Executor 'exit 1' for task '8c9b137b-31dd-465a-baf1-f6b48bf33dfc' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases. 3: I1121 18:16:14.156246 18321 master.cpp:10793] Adding task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc 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 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0 at slave(452)@172.17.0.4:36588 (849074e36b7e) 3: I1121 18:16:14.157176 18321 master.cpp:4978] Launching task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 (default) at [email protected]:36588 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 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0 at slave(452)@172.17.0.4:36588 (849074e36b7e) 3: I1121 18:16:14.158102 18320 slave.cpp:1803] Got assigned task '8c9b137b-31dd-465a-baf1-f6b48bf33dfc' for framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 3: I1121 18:16:14.158861 18320 slave.cpp:2071] Authorizing task '8c9b137b-31dd-465a-baf1-f6b48bf33dfc' for framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 3: I1121 18:16:14.158958 18320 slave.cpp:7264] Authorizing framework principal 'test-principal' to launch task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc 3: I1121 18:16:14.159888 18310 slave.cpp:2239] Launching task '8c9b137b-31dd-465a-baf1-f6b48bf33dfc' for framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 3: I1121 18:16:14.160573 18310 paths.cpp:621] Trying to chown '/tmp/OversubscriptionTest_FetchResourceUsage_sw3G8n/slaves/5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0/frameworks/5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000/executors/exit 1/runs/c255d1b6-dba3-4cf7-8211-1452b49bf7ef' to user 'mesos' 3: I1121 18:16:14.160871 18310 slave.cpp:7738] Launching executor 'exit 1' of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 with resources [] in work directory '/tmp/OversubscriptionTest_FetchResourceUsage_sw3G8n/slaves/5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0/frameworks/5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000/executors/exit 1/runs/c255d1b6-dba3-4cf7-8211-1452b49bf7ef' 3: I1121 18:16:14.161801 18310 slave.cpp:2467] Queued task '8c9b137b-31dd-465a-baf1-f6b48bf33dfc' for executor 'exit 1' of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 3: I1121 18:16:14.161914 18310 slave.cpp:958] Successfully attached '/tmp/OversubscriptionTest_FetchResourceUsage_sw3G8n/slaves/5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0/frameworks/5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000/executors/exit 1/runs/c255d1b6-dba3-4cf7-8211-1452b49bf7ef' to virtual path '/tmp/OversubscriptionTest_FetchResourceUsage_sw3G8n/slaves/5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0/frameworks/5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000/executors/exit 1/runs/latest' 3: I1121 18:16:14.161958 18310 slave.cpp:958] Successfully attached '/tmp/OversubscriptionTest_FetchResourceUsage_sw3G8n/slaves/5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0/frameworks/5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000/executors/exit 1/runs/c255d1b6-dba3-4cf7-8211-1452b49bf7ef' to virtual path '/frameworks/5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000/executors/exit 1/runs/latest' 3: I1121 18:16:14.162006 18310 slave.cpp:958] Successfully attached '/tmp/OversubscriptionTest_FetchResourceUsage_sw3G8n/slaves/5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0/frameworks/5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000/executors/exit 1/runs/c255d1b6-dba3-4cf7-8211-1452b49bf7ef' to virtual path '/tmp/OversubscriptionTest_FetchResourceUsage_sw3G8n/slaves/5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0/frameworks/5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000/executors/exit 1/runs/c255d1b6-dba3-4cf7-8211-1452b49bf7ef' 3: I1121 18:16:14.162379 18310 slave.cpp:2930] Launching container c255d1b6-dba3-4cf7-8211-1452b49bf7ef for executor 'exit 1' of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 3: W1121 18:16:14.166237 18303 process.cpp:2756] Attempted to spawn already running process [email protected]:36588 3: I1121 18:16:14.166510 18303 exec.cpp:162] Version: 1.5.0 3: I1121 18:16:14.166870 18312 exec.cpp:212] Executor started at: executor(165)@172.17.0.4:36588 with pid 18300 3: I1121 18:16:14.167253 18311 slave.cpp:4063] Got registration for executor 'exit 1' of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 from executor(165)@172.17.0.4:36588 3: I1121 18:16:14.167840 18304 exec.cpp:237] Executor registered on agent 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0 3: I1121 18:16:14.167891 18304 exec.cpp:249] Executor::registered took 36255ns 3: I1121 18:16:14.168515 18311 slave.cpp:2669] Sending queued task '8c9b137b-31dd-465a-baf1-f6b48bf33dfc' to executor 'exit 1' of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 at executor(165)@172.17.0.4:36588 3: I1121 18:16:14.168915 18308 exec.cpp:331] Executor asked to run task '8c9b137b-31dd-465a-baf1-f6b48bf33dfc' 3: I1121 18:16:14.169014 18308 exec.cpp:340] Executor::launchTask took 87723ns 3: I1121 18:16:14.169128 18308 exec.cpp:571] Executor sending status update TASK_RUNNING (UUID: 049fcaa2-ac39-4dc1-81ad-a460681f343b) for task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 3: I1121 18:16:14.169548 18314 slave.cpp:4517] Handling status update TASK_RUNNING (UUID: 049fcaa2-ac39-4dc1-81ad-a460681f343b) for task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 from executor(165)@172.17.0.4:36588 3: I1121 18:16:14.170215 18306 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (UUID: 049fcaa2-ac39-4dc1-81ad-a460681f343b) for task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 3: I1121 18:16:14.170264 18306 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 3: I1121 18:16:14.170925 18306 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (UUID: 049fcaa2-ac39-4dc1-81ad-a460681f343b) for task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 to the agent 3: I1121 18:16:14.171171 18316 slave.cpp:5000] Forwarding the update TASK_RUNNING (UUID: 049fcaa2-ac39-4dc1-81ad-a460681f343b) for task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 to [email protected]:36588 3: I1121 18:16:14.171434 18316 slave.cpp:4893] Task status update manager successfully handled status update TASK_RUNNING (UUID: 049fcaa2-ac39-4dc1-81ad-a460681f343b) for task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 3: I1121 18:16:14.171489 18316 slave.cpp:4909] Sending acknowledgement for status update TASK_RUNNING (UUID: 049fcaa2-ac39-4dc1-81ad-a460681f343b) for task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 to executor(165)@172.17.0.4:36588 3: I1121 18:16:14.171649 18318 master.cpp:7268] Status update TASK_RUNNING (UUID: 049fcaa2-ac39-4dc1-81ad-a460681f343b) for task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 from agent 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0 at slave(452)@172.17.0.4:36588 (849074e36b7e) 3: I1121 18:16:14.171672 18316 exec.cpp:388] Executor received status update acknowledgement 049fcaa2-ac39-4dc1-81ad-a460681f343b for task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 3: I1121 18:16:14.171717 18318 master.cpp:7330] Forwarding status update TASK_RUNNING (UUID: 049fcaa2-ac39-4dc1-81ad-a460681f343b) for task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 3: I1121 18:16:14.171947 18318 master.cpp:9523] Updating the state of task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING) 3: I1121 18:16:14.172317 18319 sched.cpp:1029] Scheduler::statusUpdate took 96826ns 3: I1121 18:16:14.172827 18309 master.cpp:5793] Processing ACKNOWLEDGE call 049fcaa2-ac39-4dc1-81ad-a460681f343b for task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 (default) at [email protected]:36588 on agent 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0 3: I1121 18:16:14.173611 18304 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 049fcaa2-ac39-4dc1-81ad-a460681f343b) for task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 3: I1121 18:16:14.173848 18322 slave.cpp:3801] Task status update manager successfully handled status update acknowledgement (UUID: 049fcaa2-ac39-4dc1-81ad-a460681f343b) for task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 3: I1121 18:16:14.174914 18300 sched.cpp:2009] Asked to stop the driver 3: I1121 18:16:14.175022 18323 sched.cpp:1191] Stopping framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 3: I1121 18:16:14.175487 18313 master.cpp:8813] Processing TEARDOWN call for framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 (default) at [email protected]:36588 3: I1121 18:16:14.175523 18313 master.cpp:8825] Removing framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 (default) at [email protected]:36588 3: I1121 18:16:14.175539 18313 master.cpp:3333] Deactivating framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 (default) at [email protected]:36588 3: I1121 18:16:14.175717 18318 hierarchical.cpp:419] Deactivated framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 3: I1121 18:16:14.175781 18313 master.cpp:9523] Updating the state of task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED) 3: I1121 18:16:14.175899 18320 slave.cpp:3267] Asked to shut down framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 by [email protected]:36588 3: I1121 18:16:14.175931 18320 slave.cpp:3292] Shutting down framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 3: I1121 18:16:14.175987 18320 slave.cpp:5876] Shutting down executor 'exit 1' of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 at executor(165)@172.17.0.4:36588 3: I1121 18:16:14.176187 18320 exec.cpp:435] Executor asked to shutdown 3: I1121 18:16:14.176259 18320 exec.cpp:450] Executor::shutdown took 64292ns 3: I1121 18:16:14.176580 18322 slave.cpp:5132] Got exited event for executor(165)@172.17.0.4:36588 3: I1121 18:16:14.176736 18313 master.cpp:9617] Removing task 8c9b137b-31dd-465a-baf1-f6b48bf33dfc 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"}] of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 on agent 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0 at slave(452)@172.17.0.4:36588 (849074e36b7e) 3: I1121 18:16:14.177136 18319 hierarchical.cpp:1132] 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 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0 from framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 3: I1121 18:16:14.177469 18313 master.cpp:9646] Removing executor 'exit 1' with resources [] of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 on agent 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-S0 at slave(452)@172.17.0.4:36588 (849074e36b7e) 3: I1121 18:16:14.180064 18320 slave.cpp:5541] Executor 'exit 1' of framework 5574c9f4-66e2-4bd5-a4f5-c6cc19ab65d3-0000 exited with status 0 write /dev/stdout: resource temporarily unavailable Build step 'Execute shell' marked build as failure
