See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,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)/4585/display/redirect?page=changes>
Changes: [xujyan] Added a new reason to task status. [xujyan] Send status updates when an unreachable agent re-registers. ------------------------------------------ [...truncated 3.59 MB...] 3: I1212 19:41:11.274335 20108 master.cpp:9442] Removing framework b8b160d3-6f05-43bc-975c-5b6964cce6d9-0000 (default) at [email protected]:44796 3: I1212 19:41:11.274346 20108 master.cpp:3327] Deactivating framework b8b160d3-6f05-43bc-975c-5b6964cce6d9-0000 (default) at [email protected]:44796 3: I1212 19:41:11.274452 20126 hierarchical.cpp:405] Deactivated framework b8b160d3-6f05-43bc-975c-5b6964cce6d9-0000 3: I1212 19:41:11.274847 20108 master.cpp:10671] Removing offer b8b160d3-6f05-43bc-975c-5b6964cce6d9-O0 3: I1212 19:41:11.275043 20117 slave.cpp:3375] Asked to shut down framework b8b160d3-6f05-43bc-975c-5b6964cce6d9-0000 by [email protected]:44796 3: I1212 19:41:11.275066 20117 slave.cpp:3390] Cannot shut down unknown framework b8b160d3-6f05-43bc-975c-5b6964cce6d9-0000 3: I1212 19:41:11.275225 20106 slave.cpp:909] Agent terminating 3: I1212 19:41:11.275425 20111 master.cpp:1305] Agent b8b160d3-6f05-43bc-975c-5b6964cce6d9-S0 at slave(57)@172.17.0.2:44796 (0d2e85c105fe) disconnected 3: I1212 19:41:11.275449 20111 master.cpp:3364] Disconnecting agent b8b160d3-6f05-43bc-975c-5b6964cce6d9-S0 at slave(57)@172.17.0.2:44796 (0d2e85c105fe) 3: I1212 19:41:11.275488 20111 master.cpp:3383] Deactivating agent b8b160d3-6f05-43bc-975c-5b6964cce6d9-S0 at slave(57)@172.17.0.2:44796 (0d2e85c105fe) 3: I1212 19:41:11.275635 20119 hierarchical.cpp:1192] 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 b8b160d3-6f05-43bc-975c-5b6964cce6d9-S0 from framework b8b160d3-6f05-43bc-975c-5b6964cce6d9-0000 3: I1212 19:41:11.276012 20119 hierarchical.cpp:344] Removed framework b8b160d3-6f05-43bc-975c-5b6964cce6d9-0000 3: I1212 19:41:11.276068 20119 hierarchical.cpp:766] Agent b8b160d3-6f05-43bc-975c-5b6964cce6d9-S0 deactivated 3: I1212 19:41:11.282845 20106 master.cpp:1147] Master terminating 3: I1212 19:41:11.283450 20108 hierarchical.cpp:609] Removed agent b8b160d3-6f05-43bc-975c-5b6964cce6d9-S0 3: [ OK ] FaultToleranceTest.SlaveReliableRegistration (61 ms) 3: [ RUN ] FaultToleranceTest.SlaveReregisterOnZKExpiration 3: I1212 19:41:11.288810 20106 cluster.cpp:172] Creating default 'local' authorizer 3: I1212 19:41:11.291752 20117 master.cpp:456] Master f4f5bbf0-3993-4787-93fe-413d32fa80bd (0d2e85c105fe) started on 172.17.0.2:44796 3: I1212 19:41:11.291771 20117 master.cpp:458] 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/KRvpp3/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/KRvpp3/master" --zk_session_timeout="10secs" 3: I1212 19:41:11.292035 20117 master.cpp:507] Master only allowing authenticated frameworks to register 3: I1212 19:41:11.292043 20117 master.cpp:513] Master only allowing authenticated agents to register 3: I1212 19:41:11.292047 20117 master.cpp:519] Master only allowing authenticated HTTP frameworks to register 3: I1212 19:41:11.292052 20117 credentials.hpp:37] Loading credentials for authentication from '/tmp/KRvpp3/credentials' 3: I1212 19:41:11.292302 20117 master.cpp:563] Using default 'crammd5' authenticator 3: I1212 19:41:11.292477 20117 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' 3: I1212 19:41:11.292675 20117 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' 3: I1212 19:41:11.292850 20117 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' 3: I1212 19:41:11.292985 20117 master.cpp:642] Authorization enabled 3: I1212 19:41:11.293186 20112 hierarchical.cpp:175] Initialized hierarchical allocator process 3: I1212 19:41:11.293269 20118 whitelist_watcher.cpp:77] No whitelist given 3: I1212 19:41:11.296247 20129 master.cpp:2209] Elected as the leading master! 3: I1212 19:41:11.296277 20129 master.cpp:1689] Recovering from registrar 3: I1212 19:41:11.296437 20125 registrar.cpp:347] Recovering registrar 3: I1212 19:41:11.297091 20125 registrar.cpp:391] Successfully fetched the registry (0B) in 611072ns 3: I1212 19:41:11.297193 20125 registrar.cpp:495] Applied 1 operations in 25837ns; attempting to update the registry 3: I1212 19:41:11.297672 20128 registrar.cpp:552] Successfully updated the registry in 436992ns 3: I1212 19:41:11.297796 20128 registrar.cpp:424] Successfully recovered registrar 3: I1212 19:41:11.298208 20113 master.cpp:1802] Recovered 0 agents from the registry (135B); allowing 10mins for agents to re-register 3: I1212 19:41:11.298247 20123 hierarchical.cpp:213] Skipping recovery of hierarchical allocator: nothing to recover 3: W1212 19:41:11.302510 20106 process.cpp:2756] Attempted to spawn already running process [email protected]:44796 3: I1212 19:41:11.303366 20106 containerizer.cpp:304] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } 3: W1212 19:41:11.303851 20106 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges 3: W1212 19:41:11.303959 20106 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges 3: I1212 19:41:11.303989 20106 provisioner.cpp:299] Using default backend 'copy' 3: I1212 19:41:11.305805 20106 cluster.cpp:460] Creating default 'local' authorizer 3: I1212 19:41:11.308241 20112 slave.cpp:258] Mesos agent started on (58)@172.17.0.2:44796 3: I1212 19:41:11.308262 20112 slave.cpp:259] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/FaultToleranceTest_SlaveReregisterOnZKExpiration_gm2riF/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/FaultToleranceTest_SlaveReregisterOnZKExpiration_gm2riF/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/FaultToleranceTest_SlaveReregisterOnZKExpiration_gm2riF/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/FaultToleranceTest_SlaveReregisterOnZKExpiration_gm2riF/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/FaultToleranceTest_SlaveReregisterOnZKExpiration_gm2riF/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --jwt_secret_key="/tmp/FaultToleranceTest_SlaveReregisterOnZKExpiration_gm2riF/jwt_secret_key" --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" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/FaultToleranceTest_SlaveReregisterOnZKExpiration_gm2riF" --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/FaultToleranceTest_SlaveReregisterOnZKExpiration_qPlVlm" --zk_session_timeout="10secs" 3: I1212 19:41:11.308816 20112 credentials.hpp:86] Loading credential for authentication from '/tmp/FaultToleranceTest_SlaveReregisterOnZKExpiration_gm2riF/credential' 3: I1212 19:41:11.309092 20112 slave.cpp:291] Agent using credential for: test-principal 3: I1212 19:41:11.309108 20112 credentials.hpp:37] Loading credentials for authentication from '/tmp/FaultToleranceTest_SlaveReregisterOnZKExpiration_gm2riF/http_credentials' 3: I1212 19:41:11.309491 20112 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor' 3: I1212 19:41:11.309665 20112 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor' 3: I1212 19:41:11.309985 20112 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1212 19:41:11.310096 20112 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1212 19:41:11.310408 20112 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1212 19:41:11.310567 20112 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1212 19:41:11.313151 20112 slave.cpp:590] 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: I1212 19:41:11.313549 20112 slave.cpp:598] Agent attributes: [ ] 3: I1212 19:41:11.313558 20112 slave.cpp:607] Agent hostname: 0d2e85c105fe 3: I1212 19:41:11.313738 20107 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1212 19:41:11.315963 20110 state.cpp:66] Recovering state from '/tmp/FaultToleranceTest_SlaveReregisterOnZKExpiration_qPlVlm/meta' 3: I1212 19:41:11.316431 20120 task_status_update_manager.cpp:207] Recovering task status update manager 3: I1212 19:41:11.316642 20114 containerizer.cpp:674] Recovering containerizer 3: I1212 19:41:11.318536 20128 provisioner.cpp:495] Provisioner recovery complete 3: I1212 19:41:11.318931 20109 slave.cpp:6724] Finished recovery 3: I1212 19:41:11.319654 20130 slave.cpp:1033] New master detected at [email protected]:44796 3: I1212 19:41:11.319679 20112 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1212 19:41:11.319728 20130 slave.cpp:1088] Detecting new master 3: I1212 19:41:11.326021 20110 slave.cpp:1115] Authenticating with master [email protected]:44796 3: I1212 19:41:11.326090 20110 slave.cpp:1124] Using default CRAM-MD5 authenticatee 3: I1212 19:41:11.326427 20117 authenticatee.cpp:121] Creating new client SASL connection 3: I1212 19:41:11.326823 20120 master.cpp:8920] Authenticating slave(58)@172.17.0.2:44796 3: I1212 19:41:11.326988 20115 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(124)@172.17.0.2:44796 3: I1212 19:41:11.327263 20124 authenticator.cpp:98] Creating new server SASL connection 3: I1212 19:41:11.327525 20129 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1212 19:41:11.327574 20129 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1212 19:41:11.327697 20129 authenticator.cpp:204] Received SASL authentication start 3: I1212 19:41:11.327749 20129 authenticator.cpp:326] Authentication requires more steps 3: I1212 19:41:11.327867 20119 authenticatee.cpp:259] Received SASL authentication step 3: I1212 19:41:11.327997 20121 authenticator.cpp:232] Received SASL authentication step 3: I1212 19:41:11.328033 20121 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '0d2e85c105fe' server FQDN: '0d2e85c105fe' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1212 19:41:11.328050 20121 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1212 19:41:11.328083 20121 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1212 19:41:11.328109 20121 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '0d2e85c105fe' server FQDN: '0d2e85c105fe' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1212 19:41:11.328125 20121 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1212 19:41:11.328132 20121 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1212 19:41:11.328150 20121 authenticator.cpp:318] Authentication success 3: I1212 19:41:11.328339 20125 authenticatee.cpp:299] Authentication success 3: I1212 19:41:11.328367 20122 master.cpp:8950] Successfully authenticated principal 'test-principal' at slave(58)@172.17.0.2:44796 3: I1212 19:41:11.328508 20114 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(124)@172.17.0.2:44796 3: I1212 19:41:11.328776 20125 slave.cpp:1207] Successfully authenticated with master [email protected]:44796 3: I1212 19:41:11.328981 20125 slave.cpp:1684] Will retry registration in 3.443323ms if necessary 3: I1212 19:41:11.329138 20107 master.cpp:6077] Received register agent message from slave(58)@172.17.0.2:44796 (0d2e85c105fe) 3: I1212 19:41:11.329208 20107 master.cpp:3866] Authorizing agent with principal 'test-principal' 3: I1212 19:41:11.329557 20127 master.cpp:6147] Authorized registration of agent at slave(58)@172.17.0.2:44796 (0d2e85c105fe) 3: I1212 19:41:11.329619 20127 master.cpp:6240] Registering agent at slave(58)@172.17.0.2:44796 (0d2e85c105fe) with id f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 3: I1212 19:41:11.330015 20127 registrar.cpp:495] Applied 1 operations in 68440ns; attempting to update the registry 3: I1212 19:41:11.330520 20127 registrar.cpp:552] Successfully updated the registry in 460032ns 3: I1212 19:41:11.330657 20110 master.cpp:6288] Admitted agent f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 at slave(58)@172.17.0.2:44796 (0d2e85c105fe) 3: I1212 19:41:11.331318 20110 master.cpp:6337] Registered agent f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 at slave(58)@172.17.0.2:44796 (0d2e85c105fe) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] 3: I1212 19:41:11.331640 20120 slave.cpp:1253] Registered with master [email protected]:44796; given agent ID f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 3: I1212 19:41:11.331795 20119 task_status_update_manager.cpp:188] Resuming sending task status updates 3: I1212 19:41:11.331887 20115 hierarchical.cpp:574] Added agent f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 (0d2e85c105fe) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {}) 3: I1212 19:41:11.331938 20120 slave.cpp:1273] Checkpointing SlaveInfo to '/tmp/FaultToleranceTest_SlaveReregisterOnZKExpiration_qPlVlm/meta/slaves/f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0/slave.info' 3: I1212 19:41:11.332206 20115 hierarchical.cpp:1517] Performed allocation for 1 agents in 137549ns 3: W1212 19:41:11.332412 20106 process.cpp:2756] Attempted to spawn already running process [email protected]:44796 3: I1212 19:41:11.332394 20120 slave.cpp:1330] Forwarding agent update {"offer_operations":{},"resource_categories":{"oversubscribed":true},"resource_version_uuid":"D7WukzAcRvGXlp9HCkvJVQ==","slave_id":{"value":"f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0"}} 3: I1212 19:41:11.332590 20108 master.cpp:7270] Received update of agent f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 at slave(58)@172.17.0.2:44796 (0d2e85c105fe) with total oversubscribed resources {} 3: I1212 19:41:11.332798 20108 master.cpp:7368] Ignoring update on agent f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 at slave(58)@172.17.0.2:44796 (0d2e85c105fe) as it reports no changes 3: I1212 19:41:11.333417 20106 sched.cpp:232] Version: 1.5.0 3: I1212 19:41:11.334084 20112 sched.cpp:336] New master detected at [email protected]:44796 3: I1212 19:41:11.334223 20112 sched.cpp:396] Authenticating with master [email protected]:44796 3: I1212 19:41:11.334239 20112 sched.cpp:403] Using default CRAM-MD5 authenticatee 3: I1212 19:41:11.334564 20113 authenticatee.cpp:121] Creating new client SASL connection 3: I1212 19:41:11.334851 20123 master.cpp:8920] Authenticating [email protected]:44796 3: I1212 19:41:11.334990 20127 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(125)@172.17.0.2:44796 3: I1212 19:41:11.335263 20117 authenticator.cpp:98] Creating new server SASL connection 3: I1212 19:41:11.335546 20110 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1212 19:41:11.335572 20110 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1212 19:41:11.335703 20124 authenticator.cpp:204] Received SASL authentication start 3: I1212 19:41:11.335810 20124 authenticator.cpp:326] Authentication requires more steps 3: I1212 19:41:11.335952 20124 authenticatee.cpp:259] Received SASL authentication step 3: I1212 19:41:11.336081 20124 authenticator.cpp:232] Received SASL authentication step 3: I1212 19:41:11.336103 20124 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '0d2e85c105fe' server FQDN: '0d2e85c105fe' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1212 19:41:11.336127 20124 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1212 19:41:11.336194 20124 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1212 19:41:11.336210 20124 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '0d2e85c105fe' server FQDN: '0d2e85c105fe' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1212 19:41:11.336216 20124 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1212 19:41:11.336221 20124 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1212 19:41:11.336233 20124 authenticator.cpp:318] Authentication success 3: I1212 19:41:11.336364 20129 authenticatee.cpp:299] Authentication success 3: I1212 19:41:11.336431 20126 master.cpp:8950] Successfully authenticated principal 'test-principal' at [email protected]:44796 3: I1212 19:41:11.336539 20129 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(125)@172.17.0.2:44796 3: I1212 19:41:11.336639 20115 sched.cpp:502] Successfully authenticated with master [email protected]:44796 3: I1212 19:41:11.336661 20115 sched.cpp:824] Sending SUBSCRIBE call to [email protected]:44796 3: I1212 19:41:11.336760 20115 sched.cpp:857] Will retry registration in 948.192601ms if necessary 3: I1212 19:41:11.336923 20128 master.cpp:2957] Received SUBSCRIBE call for framework 'default' at [email protected]:44796 3: I1212 19:41:11.336997 20128 master.cpp:2274] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' 3: I1212 19:41:11.337815 20109 master.cpp:3037] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] 3: I1212 19:41:11.338019 20109 master.cpp:9141] Adding framework f4f5bbf0-3993-4787-93fe-413d32fa80bd-0000 (default) at [email protected]:44796 with roles { } suppressed 3: I1212 19:41:11.338562 20118 sched.cpp:751] Framework registered with f4f5bbf0-3993-4787-93fe-413d32fa80bd-0000 3: I1212 19:41:11.338608 20118 sched.cpp:765] Scheduler::registered took 20333ns 3: I1212 19:41:11.338785 20107 hierarchical.cpp:297] Added framework f4f5bbf0-3993-4787-93fe-413d32fa80bd-0000 3: I1212 19:41:11.340093 20107 hierarchical.cpp:1517] Performed allocation for 1 agents in 1.171204ms 3: I1212 19:41:11.340737 20130 master.cpp:8750] Sending 1 offers to framework f4f5bbf0-3993-4787-93fe-413d32fa80bd-0000 (default) at [email protected]:44796 3: I1212 19:41:11.341305 20130 sched.cpp:921] Scheduler::resourceOffers took 51429ns 3: I1212 19:41:11.342161 20126 slave.cpp:1033] New master detected at [email protected]:44796 3: I1212 19:41:11.342221 20122 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1212 19:41:11.342249 20126 slave.cpp:1088] Detecting new master 3: I1212 19:41:11.345706 20120 slave.cpp:1115] Authenticating with master [email protected]:44796 3: I1212 19:41:11.345757 20120 slave.cpp:1124] Using default CRAM-MD5 authenticatee 3: I1212 19:41:11.345947 20108 authenticatee.cpp:121] Creating new client SASL connection 3: I1212 19:41:11.346212 20129 master.cpp:8920] Authenticating slave(58)@172.17.0.2:44796 3: I1212 19:41:11.346398 20115 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(126)@172.17.0.2:44796 3: I1212 19:41:11.346688 20128 authenticator.cpp:98] Creating new server SASL connection 3: I1212 19:41:11.347079 20114 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1212 19:41:11.347128 20114 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1212 19:41:11.347255 20114 authenticator.cpp:204] Received SASL authentication start 3: I1212 19:41:11.347337 20114 authenticator.cpp:326] Authentication requires more steps 3: I1212 19:41:11.347487 20114 authenticatee.cpp:259] Received SASL authentication step 3: I1212 19:41:11.347656 20114 authenticator.cpp:232] Received SASL authentication step 3: I1212 19:41:11.347695 20114 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '0d2e85c105fe' server FQDN: '0d2e85c105fe' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1212 19:41:11.347712 20114 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1212 19:41:11.347741 20114 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1212 19:41:11.347769 20114 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '0d2e85c105fe' server FQDN: '0d2e85c105fe' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1212 19:41:11.347782 20114 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1212 19:41:11.347790 20114 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1212 19:41:11.347807 20114 authenticator.cpp:318] Authentication success 3: I1212 19:41:11.347965 20112 authenticatee.cpp:299] Authentication success 3: I1212 19:41:11.348079 20113 master.cpp:8950] Successfully authenticated principal 'test-principal' at slave(58)@172.17.0.2:44796 3: I1212 19:41:11.348116 20107 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(126)@172.17.0.2:44796 3: I1212 19:41:11.348285 20123 slave.cpp:1207] Successfully authenticated with master [email protected]:44796 3: I1212 19:41:11.348455 20123 slave.cpp:1684] Will retry registration in 7.790068ms if necessary 3: I1212 19:41:11.348626 20117 master.cpp:6416] Received re-register agent message from agent f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 at slave(58)@172.17.0.2:44796 (0d2e85c105fe) 3: I1212 19:41:11.348702 20117 master.cpp:3866] Authorizing agent with principal 'test-principal' 3: I1212 19:41:11.349175 20124 master.cpp:6505] Authorized re-registration of agent f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 at slave(58)@172.17.0.2:44796 (0d2e85c105fe) 3: I1212 19:41:11.349269 20124 master.cpp:6571] Agent is already marked as registered: f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 at slave(58)@172.17.0.2:44796 (0d2e85c105fe) 3: I1212 19:41:11.349483 20124 master.cpp:6948] Registry updated for slave f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 at slave(58)@172.17.0.2:44796(0d2e85c105fe) 3: I1212 19:41:11.349951 20124 master.cpp:7109] Sending updated checkpointed resources {} to agent f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 at slave(58)@172.17.0.2:44796 (0d2e85c105fe) 3: I1212 19:41:11.350082 20119 hierarchical.cpp:669] Agent f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 (0d2e85c105fe) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000] 3: I1212 19:41:11.350097 20122 slave.cpp:1366] Re-registered with master [email protected]:44796 3: I1212 19:41:11.350204 20108 task_status_update_manager.cpp:188] Resuming sending task status updates 3: I1212 19:41:11.350371 20106 sched.cpp:2009] Asked to stop the driver 3: I1212 19:41:11.350371 20122 slave.cpp:1411] Forwarding agent update {"offer_operations":{},"resource_categories":{"oversubscribed":true},"resource_version_uuid":"D7WukzAcRvGXlp9HCkvJVQ==","slave_id":{"value":"f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0"}} 3: I1212 19:41:11.350608 20128 sched.cpp:1191] Stopping framework f4f5bbf0-3993-4787-93fe-413d32fa80bd-0000 3: I1212 19:41:11.350638 20109 master.cpp:7270] Received update of agent f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 at slave(58)@172.17.0.2:44796 (0d2e85c105fe) with total oversubscribed resources {} 3: I1212 19:41:11.350615 20122 slave.cpp:3624] Ignoring new checkpointed resources identical to the current version: {} 3: I1212 19:41:11.350878 20109 master.cpp:7368] Ignoring update on agent f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 at slave(58)@172.17.0.2:44796 (0d2e85c105fe) as it reports no changes 3: I1212 19:41:11.351059 20109 master.cpp:9430] Processing TEARDOWN call for framework f4f5bbf0-3993-4787-93fe-413d32fa80bd-0000 (default) at [email protected]:44796 3: I1212 19:41:11.351085 20109 master.cpp:9442] Removing framework f4f5bbf0-3993-4787-93fe-413d32fa80bd-0000 (default) at [email protected]:44796 3: I1212 19:41:11.351097 20109 master.cpp:3327] Deactivating framework f4f5bbf0-3993-4787-93fe-413d32fa80bd-0000 (default) at [email protected]:44796 3: I1212 19:41:11.351264 20113 hierarchical.cpp:405] Deactivated framework f4f5bbf0-3993-4787-93fe-413d32fa80bd-0000 3: I1212 19:41:11.351601 20106 slave.cpp:909] Agent terminating 3: I1212 19:41:11.351711 20109 master.cpp:10671] Removing offer f4f5bbf0-3993-4787-93fe-413d32fa80bd-O0 3: I1212 19:41:11.352478 20109 master.cpp:1305] Agent f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 at slave(58)@172.17.0.2:44796 (0d2e85c105fe) disconnected 3: I1212 19:41:11.352496 20109 master.cpp:3364] Disconnecting agent f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 at slave(58)@172.17.0.2:44796 (0d2e85c105fe) 3: I1212 19:41:11.352535 20109 master.cpp:3383] Deactivating agent f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 at slave(58)@172.17.0.2:44796 (0d2e85c105fe) 3: I1212 19:41:11.352618 20113 hierarchical.cpp:1192] 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 f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 from framework f4f5bbf0-3993-4787-93fe-413d32fa80bd-0000 3: I1212 19:41:11.352928 20113 hierarchical.cpp:344] Removed framework f4f5bbf0-3993-4787-93fe-413d32fa80bd-0000 3: I1212 19:41:11.352986 20113 hierarchical.cpp:766] Agent f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 deactivated 3: I1212 19:41:11.360822 20121 master.cpp:1147] Master terminating 3: I1212 19:41:11.361801 20110 hierarchical.cpp:609] Removed agent f4f5bbf0-3993-4787-93fe-413d32fa80bd-S0 3: [ OK ] FaultToleranceTest.SlaveReregisterOnZKExpiration (79 ms) 3: [ RUN ] FaultToleranceTest.FrameworkReregisterEmptyExecutor 3: I1212 19:41:11.367681 20106 cluster.cpp:172] Creating default 'local' authorizer 3: I1212 19:41:11.370422 20121 master.cpp:456] Master 17d89c48-3ed6-4ab4-9554-278ce3a0b25e (0d2e85c105fe) started on 172.17.0.2:44796 3: I1212 19:41:11.370460 20121 master.cpp:458] 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/mQbcpA/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/mQbcpA/master" --zk_session_timeout="10secs" 3: I1212 19:41:11.371012 20121 master.cpp:507] Master only allowing authenticated frameworks to register 3: I1212 19:41:11.371026 20121 master.cpp:513] Master only allowing authenticated agents to register 3: I1212 19:41:11.371032 20121 master.cpp:519] Master only allowing authenticated HTTP frameworks to register 3: I1212 19:41:11.371052 20121 credentials.hpp:37] Loading credentials for authentication from '/tmp/mQbcpA/credentials' 3: I1212 19:41:11.371506 20121 master.cpp:563] Using default 'crammd5' authenticator 3: I1212 19:41:11.371717 20121 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' 3: I1212 19:41:11.371927 20121 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' 3: I1212 19:41:11.372092 20121 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' 3: I1212 19:41:11.372247 20121 master.cpp:642] Authorization enabled 3: I1212 19:41:11.372447 20127 hierarchical.cpp:175] Initialized hierarchical allocator process 3: I1212 19:41:11.372512 20112 whitelist_watcher.cpp:77] No whitelist given 3: I1212 19:41:11.375988 20113 master.cpp:2209] Elected as the leading master! 3: I1212 19:41:11.376029 20113 master.cpp:1689] Recovering from registrar 3: I1212 19:41:11.376288 20115 registrar.cpp:347] Recovering registrar 3: I1212 19:41:11.377032 20115 registrar.cpp:391] Successfully fetched the registry (0B) in 689152ns 3: I1212 19:41:11.377189 20115 registrar.cpp:495] Applied 1 operations in 30287ns; attempting to update the registry 3: I1212 19:41:11.377821 20115 registrar.cpp:552] Successfully updated the registry in 578048ns 3: I1212 19:41:11.377960 20115 registrar.cpp:424] Successfully recovered registrar 3: I1212 19:41:11.378454 20118 master.cpp:1802] Recovered 0 agents from the registry (135B); allowing 10mins for agents to re-register 3: I1212 19:41:11.378499 20122 hierarchical.cpp:213] Skipping recovery of hierarchical allocator: nothing to recover 3: W1212 19:41:11.383136 20106 process.cpp:2756] Attempted to spawn already running process [email protected]:44796 3: I1212 19:41:11.383425 20106 cluster.cpp:460] Creating default 'local' authorizer 3: I1212 19:41:11.386569 20110 slave.cpp:258] Mesos agent started on (59)@172.17.0.2:44796 3: W1212 19:41:11.387109 20106 process.cpp:2756] Attempted to spawn already running process [email protected]:44796 3: I1212 19:41:11.386607 20110 slave.cpp:259] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/FaultToleranceTest_FrameworkReregisterEmptyExecutor_kjhfGc/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/FaultToleranceTest_FrameworkReregisterEmptyExecutor_kjhfGc/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/FaultToleranceTest_FrameworkReregisterEmptyExecutor_kjhfGc/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/FaultToleranceTest_FrameworkReregisterEmptyExecutor_kjhfGc/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/FaultToleranceTest_FrameworkReregisterEmptyExecutor_kjhfGc/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --jwt_secret_key="/tmp/FaultToleranceTest_FrameworkReregisterEmptyExecutor_kjhfGc/jwt_secret_key" --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" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/FaultToleranceTest_FrameworkReregisterEmptyExecutor_kjhfGc" --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/FaultToleranceTest_FrameworkReregisterEmptyExecutor_M85HxT" --zk_session_timeout="10secs" 3: I1212 19:41:11.387300 20110 credentials.hpp:86] Loading credential for authentication from '/tmp/FaultToleranceTest_FrameworkReregisterEmptyExecutor_kjhfGc/credential' 3: I1212 19:41:11.387477 20110 slave.cpp:291] Agent using credential for: test-principal 3: I1212 19:41:11.387511 20110 credentials.hpp:37] Loading credentials for authentication from '/tmp/FaultToleranceTest_FrameworkReregisterEmptyExecutor_kjhfGc/http_credentials' 3: I1212 19:41:11.387986 20110 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor' 3: I1212 19:41:11.388144 20110 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor' 3: I1212 19:41:11.388308 20106 sched.cpp:232] Version: 1.5.0 3: I1212 19:41:11.388484 20110 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1212 19:41:11.388624 20110 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1212 19:41:11.388862 20110 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' write /dev/stdout: resource temporarily unavailable + docker rmi mesos-1513105328-26963 Error response from daemon: conflict: unable to remove repository reference "mesos-1513105328-26963" (must force) - container 0d2e85c105fe is using its referenced image 676a47af9006 Build step 'Execute shell' marked build as failure Not sending mail to unregistered user [email protected] Not sending mail to unregistered user [email protected] Not sending mail to unregistered user [email protected]
