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)/4591/display/redirect?page=changes>
Changes: [songzihao1990] Added a missing check for parent container has config recovered. ------------------------------------------ [...truncated 5.64 MB...] 3: I1213 07:45:46.259783 18417 status_update_manager_process.hpp:438] Recovering offer operation status update stream 09b71f37-d9c4-4ff0-8d65-c02efd3229fa 3: I1213 07:45:46.259898 18417 status_update_manager_process.hpp:667] Replaying offer operation status update stream 09b71f37-d9c4-4ff0-8d65-c02efd3229fa 3: [libprotobuf ERROR /mesos/build/3rdparty/protobuf-3.5.0/src/protobuf-3.5.0/src/google/protobuf/message_lite.cc:121] Can't parse message of type "mesos.internal.OfferOperationStatusUpdateRecord" because it is missing required fields: type 3: W1213 07:45:46.260231 18417 status_update_manager_process.hpp:318] Failed to recover offer operation status update stream 09b71f37-d9c4-4ff0-8d65-c02efd3229fa: Failed to read file '/tmp/gPfBfW/streams/09b71f37-d9c4-4ff0-8d65-c02efd3229fa': Failed to deserialize message 3: [ OK ] OfferOperationStatusUpdateManagerTest.StrictRecoveryCorruptedFile (4 ms) 3: [----------] 15 tests from OfferOperationStatusUpdateManagerTest (91 ms total) 3: 3: [----------] 16 tests from PartitionTest 3: [ RUN ] PartitionTest.PartitionedSlave 3: I1213 07:45:46.263672 18410 cluster.cpp:172] Creating default 'local' authorizer 3: I1213 07:45:46.266423 18430 master.cpp:456] Master 57c1dfe5-4871-4234-a9be-93aab3c38243 (36573c7a8336) started on 172.17.0.4:35223 3: I1213 07:45:46.266453 18430 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/ZD3ShG/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/ZD3ShG/master" --zk_session_timeout="10secs" 3: I1213 07:45:46.266750 18430 master.cpp:507] Master only allowing authenticated frameworks to register 3: I1213 07:45:46.266760 18430 master.cpp:513] Master only allowing authenticated agents to register 3: I1213 07:45:46.266764 18430 master.cpp:519] Master only allowing authenticated HTTP frameworks to register 3: I1213 07:45:46.266769 18430 credentials.hpp:37] Loading credentials for authentication from '/tmp/ZD3ShG/credentials' 3: I1213 07:45:46.267083 18430 master.cpp:563] Using default 'crammd5' authenticator 3: I1213 07:45:46.267261 18430 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' 3: I1213 07:45:46.267426 18430 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' 3: I1213 07:45:46.267539 18430 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' 3: I1213 07:45:46.267650 18430 master.cpp:642] Authorization enabled 3: I1213 07:45:46.267791 18416 hierarchical.cpp:175] Initialized hierarchical allocator process 3: I1213 07:45:46.267819 18428 whitelist_watcher.cpp:77] No whitelist given 3: I1213 07:45:46.270691 18432 master.cpp:2209] Elected as the leading master! 3: I1213 07:45:46.270706 18432 master.cpp:1689] Recovering from registrar 3: I1213 07:45:46.270860 18431 registrar.cpp:347] Recovering registrar 3: I1213 07:45:46.271548 18418 registrar.cpp:391] Successfully fetched the registry (0B) in 646144ns 3: I1213 07:45:46.271728 18418 registrar.cpp:495] Applied 1 operations in 63730ns; attempting to update the registry 3: I1213 07:45:46.272455 18418 registrar.cpp:552] Successfully updated the registry in 669952ns 3: I1213 07:45:46.272567 18418 registrar.cpp:424] Successfully recovered registrar 3: I1213 07:45:46.272954 18419 master.cpp:1802] Recovered 0 agents from the registry (135B); allowing 10mins for agents to re-register 3: I1213 07:45:46.273027 18429 hierarchical.cpp:213] Skipping recovery of hierarchical allocator: nothing to recover 3: W1213 07:45:46.277179 18410 process.cpp:2756] Attempted to spawn already running process [email protected]:35223 3: I1213 07:45:46.278049 18410 containerizer.cpp:304] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } 3: W1213 07:45:46.278498 18410 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges 3: W1213 07:45:46.278606 18410 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges 3: I1213 07:45:46.278636 18410 provisioner.cpp:299] Using default backend 'copy' 3: I1213 07:45:46.280483 18410 cluster.cpp:460] Creating default 'local' authorizer 3: I1213 07:45:46.282598 18429 slave.cpp:258] Mesos agent started on (108)@172.17.0.4:35223 3: W1213 07:45:46.282948 18410 process.cpp:2756] Attempted to spawn already running process [email protected]:35223 3: I1213 07:45:46.282663 18429 slave.cpp:259] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/PartitionTest_PartitionedSlave_5rtFqa/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/PartitionTest_PartitionedSlave_5rtFqa/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/PartitionTest_PartitionedSlave_5rtFqa/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/PartitionTest_PartitionedSlave_5rtFqa/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/PartitionTest_PartitionedSlave_5rtFqa/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --jwt_secret_key="/tmp/PartitionTest_PartitionedSlave_5rtFqa/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/PartitionTest_PartitionedSlave_5rtFqa" --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/PartitionTest_PartitionedSlave_ixOgmq" --zk_session_timeout="10secs" 3: I1213 07:45:46.283344 18429 credentials.hpp:86] Loading credential for authentication from '/tmp/PartitionTest_PartitionedSlave_5rtFqa/credential' 3: I1213 07:45:46.283583 18429 slave.cpp:291] Agent using credential for: test-principal 3: I1213 07:45:46.283601 18429 credentials.hpp:37] Loading credentials for authentication from '/tmp/PartitionTest_PartitionedSlave_5rtFqa/http_credentials' 3: I1213 07:45:46.283810 18410 sched.cpp:232] Version: 1.5.0 3: I1213 07:45:46.283890 18429 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor' 3: I1213 07:45:46.284138 18429 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor' 3: I1213 07:45:46.284427 18429 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1213 07:45:46.284550 18429 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1213 07:45:46.284690 18425 sched.cpp:336] New master detected at [email protected]:35223 3: I1213 07:45:46.284770 18429 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1213 07:45:46.284852 18425 sched.cpp:396] Authenticating with master [email protected]:35223 3: I1213 07:45:46.284870 18425 sched.cpp:403] Using default CRAM-MD5 authenticatee 3: I1213 07:45:46.284878 18429 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1213 07:45:46.285173 18427 authenticatee.cpp:121] Creating new client SASL connection 3: I1213 07:45:46.285537 18421 master.cpp:8932] Authenticating [email protected]:35223 3: I1213 07:45:46.285662 18433 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(228)@172.17.0.4:35223 3: I1213 07:45:46.285873 18430 authenticator.cpp:98] Creating new server SASL connection 3: I1213 07:45:46.286105 18434 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1213 07:45:46.286130 18434 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1213 07:45:46.286224 18414 authenticator.cpp:204] Received SASL authentication start 3: I1213 07:45:46.286274 18414 authenticator.cpp:326] Authentication requires more steps 3: I1213 07:45:46.286370 18415 authenticatee.cpp:259] Received SASL authentication step 3: I1213 07:45:46.286484 18431 authenticator.cpp:232] Received SASL authentication step 3: I1213 07:45:46.286509 18431 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '36573c7a8336' server FQDN: '36573c7a8336' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1213 07:45:46.286521 18431 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1213 07:45:46.286559 18431 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1213 07:45:46.286581 18431 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '36573c7a8336' server FQDN: '36573c7a8336' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1213 07:45:46.286589 18431 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1213 07:45:46.286593 18431 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1213 07:45:46.286605 18431 authenticator.cpp:318] Authentication success 3: I1213 07:45:46.286680 18432 authenticatee.cpp:299] Authentication success 3: I1213 07:45:46.286772 18411 master.cpp:8962] Successfully authenticated principal 'test-principal' at [email protected]:35223 3: I1213 07:45:46.286815 18412 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(228)@172.17.0.4:35223 3: I1213 07:45:46.286630 18429 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: I1213 07:45:46.286931 18429 slave.cpp:598] Agent attributes: [ ] 3: I1213 07:45:46.286945 18429 slave.cpp:607] Agent hostname: 36573c7a8336 3: I1213 07:45:46.287117 18426 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1213 07:45:46.287241 18413 sched.cpp:502] Successfully authenticated with master [email protected]:35223 3: I1213 07:45:46.287267 18413 sched.cpp:824] Sending SUBSCRIBE call to [email protected]:35223 3: I1213 07:45:46.287461 18413 sched.cpp:857] Will retry registration in 1.229094069secs if necessary 3: I1213 07:45:46.287634 18417 master.cpp:2957] Received SUBSCRIBE call for framework 'default' at [email protected]:35223 3: I1213 07:45:46.287653 18417 master.cpp:2274] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' 3: I1213 07:45:46.288228 18425 master.cpp:3037] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] 3: I1213 07:45:46.288507 18425 master.cpp:9153] Adding framework 57c1dfe5-4871-4234-a9be-93aab3c38243-0000 (default) at [email protected]:35223 with roles { } suppressed 3: I1213 07:45:46.289067 18433 state.cpp:66] Recovering state from '/tmp/PartitionTest_PartitionedSlave_ixOgmq/meta' 3: I1213 07:45:46.289153 18427 sched.cpp:751] Framework registered with 57c1dfe5-4871-4234-a9be-93aab3c38243-0000 3: I1213 07:45:46.289211 18427 sched.cpp:765] Scheduler::registered took 40151ns 3: I1213 07:45:46.289247 18428 hierarchical.cpp:297] Added framework 57c1dfe5-4871-4234-a9be-93aab3c38243-0000 3: I1213 07:45:46.289350 18432 task_status_update_manager.cpp:207] Recovering task status update manager 3: I1213 07:45:46.289505 18418 containerizer.cpp:674] Recovering containerizer 3: I1213 07:45:46.289502 18428 hierarchical.cpp:1517] Performed allocation for 0 agents in 90096ns 3: I1213 07:45:46.290921 18421 provisioner.cpp:495] Provisioner recovery complete 3: I1213 07:45:46.291319 18430 slave.cpp:6747] Finished recovery 3: I1213 07:45:46.292168 18433 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1213 07:45:46.292183 18427 slave.cpp:1033] New master detected at [email protected]:35223 3: I1213 07:45:46.292255 18427 slave.cpp:1088] Detecting new master 3: I1213 07:45:46.295413 18431 slave.cpp:1115] Authenticating with master [email protected]:35223 3: I1213 07:45:46.295467 18431 slave.cpp:1124] Using default CRAM-MD5 authenticatee 3: I1213 07:45:46.295658 18432 authenticatee.cpp:121] Creating new client SASL connection 3: I1213 07:45:46.295862 18411 master.cpp:8932] Authenticating slave(108)@172.17.0.4:35223 3: I1213 07:45:46.295951 18428 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(229)@172.17.0.4:35223 3: I1213 07:45:46.296133 18426 authenticator.cpp:98] Creating new server SASL connection 3: I1213 07:45:46.296299 18420 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1213 07:45:46.296319 18420 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1213 07:45:46.296407 18423 authenticator.cpp:204] Received SASL authentication start 3: I1213 07:45:46.296443 18423 authenticator.cpp:326] Authentication requires more steps 3: I1213 07:45:46.296528 18412 authenticatee.cpp:259] Received SASL authentication step 3: I1213 07:45:46.296625 18417 authenticator.cpp:232] Received SASL authentication step 3: I1213 07:45:46.296653 18417 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '36573c7a8336' server FQDN: '36573c7a8336' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1213 07:45:46.296667 18417 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1213 07:45:46.296699 18417 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1213 07:45:46.296723 18417 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '36573c7a8336' server FQDN: '36573c7a8336' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1213 07:45:46.296736 18417 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1213 07:45:46.296744 18417 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1213 07:45:46.296761 18417 authenticator.cpp:318] Authentication success 3: I1213 07:45:46.296833 18424 authenticatee.cpp:299] Authentication success 3: I1213 07:45:46.296882 18418 master.cpp:8962] Successfully authenticated principal 'test-principal' at slave(108)@172.17.0.4:35223 3: I1213 07:45:46.296936 18419 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(229)@172.17.0.4:35223 3: I1213 07:45:46.297099 18416 slave.cpp:1207] Successfully authenticated with master [email protected]:35223 3: I1213 07:45:46.297300 18416 slave.cpp:1684] Will retry registration in 15.313316ms if necessary 3: I1213 07:45:46.297428 18421 master.cpp:6077] Received register agent message from slave(108)@172.17.0.4:35223 (36573c7a8336) 3: I1213 07:45:46.297464 18421 master.cpp:3866] Authorizing agent with principal 'test-principal' 3: I1213 07:45:46.298087 18430 master.cpp:6147] Authorized registration of agent at slave(108)@172.17.0.4:35223 (36573c7a8336) 3: I1213 07:45:46.298219 18430 master.cpp:6240] Registering agent at slave(108)@172.17.0.4:35223 (36573c7a8336) with id 57c1dfe5-4871-4234-a9be-93aab3c38243-S0 3: I1213 07:45:46.298750 18414 registrar.cpp:495] Applied 1 operations in 131026ns; attempting to update the registry 3: I1213 07:45:46.299566 18414 registrar.cpp:552] Successfully updated the registry in 747008ns 3: I1213 07:45:46.299732 18431 master.cpp:6288] Admitted agent 57c1dfe5-4871-4234-a9be-93aab3c38243-S0 at slave(108)@172.17.0.4:35223 (36573c7a8336) 3: I1213 07:45:46.300434 18431 master.cpp:6337] Registered agent 57c1dfe5-4871-4234-a9be-93aab3c38243-S0 at slave(108)@172.17.0.4:35223 (36573c7a8336) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] 3: I1213 07:45:46.300510 18411 slave.cpp:1253] Registered with master [email protected]:35223; given agent ID 57c1dfe5-4871-4234-a9be-93aab3c38243-S0 3: I1213 07:45:46.300578 18420 task_status_update_manager.cpp:188] Resuming sending task status updates 3: I1213 07:45:46.300784 18411 slave.cpp:1273] Checkpointing SlaveInfo to '/tmp/PartitionTest_PartitionedSlave_ixOgmq/meta/slaves/57c1dfe5-4871-4234-a9be-93aab3c38243-S0/slave.info' 3: I1213 07:45:46.300823 18428 hierarchical.cpp:574] Added agent 57c1dfe5-4871-4234-a9be-93aab3c38243-S0 (36573c7a8336) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {}) 3: I1213 07:45:46.301193 18411 slave.cpp:1330] Forwarding agent update {"offer_operations":{},"resource_categories":{"oversubscribed":true},"resource_version_uuid":"tLa5+OvXTZGrhp\/smzh\/Ow==","slave_id":{"value":"57c1dfe5-4871-4234-a9be-93aab3c38243-S0"}} 3: I1213 07:45:46.301466 18412 master.cpp:7270] Received update of agent 57c1dfe5-4871-4234-a9be-93aab3c38243-S0 at slave(108)@172.17.0.4:35223 (36573c7a8336) with total oversubscribed resources {} 3: I1213 07:45:46.301744 18412 master.cpp:7368] Ignoring update on agent 57c1dfe5-4871-4234-a9be-93aab3c38243-S0 at slave(108)@172.17.0.4:35223 (36573c7a8336) as it reports no changes 3: I1213 07:45:46.302235 18428 hierarchical.cpp:1517] Performed allocation for 1 agents in 1.284505ms 3: I1213 07:45:46.302671 18424 master.cpp:8762] Sending 1 offers to framework 57c1dfe5-4871-4234-a9be-93aab3c38243-0000 (default) at [email protected]:35223 3: I1213 07:45:46.303053 18417 sched.cpp:921] Scheduler::resourceOffers took 47624ns 3: I1213 07:45:46.303906 18416 hierarchical.cpp:1517] Performed allocation for 1 agents in 162010ns 3: I1213 07:45:46.304937 18432 hierarchical.cpp:1517] Performed allocation for 1 agents in 226255ns 3: I1213 07:45:46.305644 18412 hierarchical.cpp:1517] Performed allocation for 1 agents in 131781ns 3: I1213 07:45:46.306216 18434 hierarchical.cpp:1517] Performed allocation for 1 agents in 116696ns 3: I1213 07:45:46.306330 18422 slave.cpp:6298] Current disk usage 64.65%. Max allowed age: 1.774812749168623days 3: I1213 07:45:46.306926 18427 master.cpp:8201] Marking agent 57c1dfe5-4871-4234-a9be-93aab3c38243-S0 at slave(108)@172.17.0.4:35223 (36573c7a8336) unreachable: health check timed out 3: I1213 07:45:46.306959 18416 hierarchical.cpp:1517] Performed allocation for 1 agents in 166416ns 3: I1213 07:45:46.307421 18420 registrar.cpp:495] Applied 1 operations in 112044ns; attempting to update the registry 3: I1213 07:45:46.308014 18420 registrar.cpp:552] Successfully updated the registry in 0ns 3: I1213 07:45:46.308161 18428 master.cpp:8249] Marked agent 57c1dfe5-4871-4234-a9be-93aab3c38243-S0 at slave(108)@172.17.0.4:35223 (36573c7a8336) unreachable: health check timed out 3: I1213 07:45:46.308676 18428 master.cpp:10683] Removing offer 57c1dfe5-4871-4234-a9be-93aab3c38243-O0 3: I1213 07:45:46.308734 18417 hierarchical.cpp:609] Removed agent 57c1dfe5-4871-4234-a9be-93aab3c38243-S0 3: I1213 07:45:46.308773 18413 sched.cpp:947] Rescinded offer 57c1dfe5-4871-4234-a9be-93aab3c38243-O0 3: I1213 07:45:46.308830 18413 sched.cpp:958] Scheduler::offerRescinded took 26006ns 3: I1213 07:45:46.308971 18428 master.cpp:2126] Notifying framework 57c1dfe5-4871-4234-a9be-93aab3c38243-0000 (default) at [email protected]:35223 of lost agent 57c1dfe5-4871-4234-a9be-93aab3c38243-S0 (36573c7a8336) 3: I1213 07:45:46.309136 18418 sched.cpp:1091] Lost agent 57c1dfe5-4871-4234-a9be-93aab3c38243-S0 3: I1213 07:45:46.309181 18418 sched.cpp:1102] Scheduler::slaveLost took 30597ns 3: I1213 07:45:46.309660 18419 slave.cpp:909] Agent terminating 3: I1213 07:45:46.317319 18429 process.cpp:3503] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot' 3: I1213 07:45:46.337163 18410 sched.cpp:2009] Asked to stop the driver 3: I1213 07:45:46.337371 18433 sched.cpp:1191] Stopping framework 57c1dfe5-4871-4234-a9be-93aab3c38243-0000 3: I1213 07:45:46.337916 18429 master.cpp:9442] Processing TEARDOWN call for framework 57c1dfe5-4871-4234-a9be-93aab3c38243-0000 (default) at [email protected]:35223 3: I1213 07:45:46.337965 18429 master.cpp:9454] Removing framework 57c1dfe5-4871-4234-a9be-93aab3c38243-0000 (default) at [email protected]:35223 3: I1213 07:45:46.337983 18429 master.cpp:3327] Deactivating framework 57c1dfe5-4871-4234-a9be-93aab3c38243-0000 (default) at [email protected]:35223 3: I1213 07:45:46.338142 18416 hierarchical.cpp:405] Deactivated framework 57c1dfe5-4871-4234-a9be-93aab3c38243-0000 3: I1213 07:45:46.338676 18432 hierarchical.cpp:344] Removed framework 57c1dfe5-4871-4234-a9be-93aab3c38243-0000 3: I1213 07:45:46.338924 18410 master.cpp:1147] Master terminating 3: [ OK ] PartitionTest.PartitionedSlave (81 ms) 3: [ RUN ] PartitionTest.ReregisterSlavePartitionAware 3: I1213 07:45:46.345242 18410 cluster.cpp:172] Creating default 'local' authorizer 3: I1213 07:45:46.348273 18418 master.cpp:456] Master 2fdca1a5-bbf0-417e-8044-06ff86a31b00 (36573c7a8336) started on 172.17.0.4:35223 3: I1213 07:45:46.348304 18418 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/8JD6To/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/8JD6To/master" --zk_session_timeout="10secs" 3: I1213 07:45:46.348595 18418 master.cpp:507] Master only allowing authenticated frameworks to register 3: I1213 07:45:46.348605 18418 master.cpp:513] Master only allowing authenticated agents to register 3: I1213 07:45:46.348613 18418 master.cpp:519] Master only allowing authenticated HTTP frameworks to register 3: I1213 07:45:46.348620 18418 credentials.hpp:37] Loading credentials for authentication from '/tmp/8JD6To/credentials' 3: I1213 07:45:46.348904 18418 master.cpp:563] Using default 'crammd5' authenticator 3: I1213 07:45:46.349074 18418 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' 3: I1213 07:45:46.349247 18418 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' 3: I1213 07:45:46.349373 18418 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' 3: I1213 07:45:46.349501 18418 master.cpp:642] Authorization enabled 3: I1213 07:45:46.349639 18423 hierarchical.cpp:175] Initialized hierarchical allocator process 3: I1213 07:45:46.349683 18426 whitelist_watcher.cpp:77] No whitelist given 3: I1213 07:45:46.352831 18431 master.cpp:2209] Elected as the leading master! 3: I1213 07:45:46.352869 18431 master.cpp:1689] Recovering from registrar 3: I1213 07:45:46.353046 18428 registrar.cpp:347] Recovering registrar 3: I1213 07:45:46.353806 18428 registrar.cpp:391] Successfully fetched the registry (0B) in 0ns 3: I1213 07:45:46.353941 18428 registrar.cpp:495] Applied 1 operations in 52262ns; attempting to update the registry 3: I1213 07:45:46.354591 18428 registrar.cpp:552] Successfully updated the registry in 0ns 3: I1213 07:45:46.354723 18428 registrar.cpp:424] Successfully recovered registrar 3: I1213 07:45:46.355094 18422 master.cpp:1802] Recovered 0 agents from the registry (135B); allowing 10mins for agents to re-register 3: I1213 07:45:46.355181 18415 hierarchical.cpp:213] Skipping recovery of hierarchical allocator: nothing to recover 3: W1213 07:45:46.360004 18410 process.cpp:2756] Attempted to spawn already running process [email protected]:35223 3: I1213 07:45:46.360906 18410 containerizer.cpp:304] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } 3: W1213 07:45:46.361385 18410 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges 3: W1213 07:45:46.361510 18410 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges 3: I1213 07:45:46.361542 18410 provisioner.cpp:299] Using default backend 'copy' 3: I1213 07:45:46.363517 18410 cluster.cpp:460] Creating default 'local' authorizer 3: I1213 07:45:46.366595 18415 slave.cpp:258] Mesos agent started on (109)@172.17.0.4:35223 3: I1213 07:45:46.366667 18415 slave.cpp:259] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/PartitionTest_ReregisterSlavePartitionAware_ja0orT/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/PartitionTest_ReregisterSlavePartitionAware_ja0orT/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/PartitionTest_ReregisterSlavePartitionAware_ja0orT/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/PartitionTest_ReregisterSlavePartitionAware_ja0orT/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/PartitionTest_ReregisterSlavePartitionAware_ja0orT/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --jwt_secret_key="/tmp/PartitionTest_ReregisterSlavePartitionAware_ja0orT/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/PartitionTest_ReregisterSlavePartitionAware_ja0orT" --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/PartitionTest_ReregisterSlavePartitionAware_hg7Ja9" --zk_session_timeout="10secs" 3: I1213 07:45:46.367266 18415 credentials.hpp:86] Loading credential for authentication from '/tmp/PartitionTest_ReregisterSlavePartitionAware_ja0orT/credential' 3: W1213 07:45:46.367286 18410 process.cpp:2756] Attempted to spawn already running process [email protected]:35223 3: I1213 07:45:46.367527 18415 slave.cpp:291] Agent using credential for: test-principal 3: I1213 07:45:46.367545 18415 credentials.hpp:37] Loading credentials for authentication from '/tmp/PartitionTest_ReregisterSlavePartitionAware_ja0orT/http_credentials' 3: I1213 07:45:46.367847 18415 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor' 3: I1213 07:45:46.368114 18415 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor' 3: I1213 07:45:46.368311 18410 sched.cpp:232] Version: 1.5.0 3: I1213 07:45:46.368455 18415 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1213 07:45:46.368566 18415 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1213 07:45:46.368809 18415 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1213 07:45:46.368914 18415 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1213 07:45:46.369007 18423 hierarchical.cpp:1517] Performed allocation for 0 agents in 104324ns 3: I1213 07:45:46.369083 18417 sched.cpp:336] New master detected at [email protected]:35223 3: I1213 07:45:46.369246 18417 sched.cpp:396] Authenticating with master [email protected]:35223 3: I1213 07:45:46.369264 18417 sched.cpp:403] Using default CRAM-MD5 authenticatee 3: I1213 07:45:46.369592 18430 authenticatee.cpp:121] Creating new client SASL connection 3: I1213 07:45:46.369943 18427 master.cpp:8932] Authenticating [email protected]:35223 3: I1213 07:45:46.370097 18426 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(230)@172.17.0.4:35223 3: I1213 07:45:46.370393 18416 authenticator.cpp:98] Creating new server SASL connection 3: I1213 07:45:46.370642 18419 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1213 07:45:46.370668 18419 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1213 07:45:46.370786 18419 authenticator.cpp:204] Received SASL authentication start 3: I1213 07:45:46.370842 18419 authenticator.cpp:326] Authentication requires more steps 3: I1213 07:45:46.370983 18411 authenticatee.cpp:259] Received SASL authentication step 3: I1213 07:45:46.370931 18415 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: I1213 07:45:46.371147 18415 slave.cpp:598] Agent attributes: [ ] 3: I1213 07:45:46.371171 18412 authenticator.cpp:232] Received SASL authentication step 3: I1213 07:45:46.371181 18415 slave.cpp:607] Agent hostname: 36573c7a8336 3: I1213 07:45:46.371203 18412 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '36573c7a8336' server FQDN: '36573c7a8336' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1213 07:45:46.371217 18412 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1213 07:45:46.371259 18412 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1213 07:45:46.371276 18412 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '36573c7a8336' server FQDN: '36573c7a8336' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1213 07:45:46.371285 18412 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1213 07:45:46.371290 18412 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1213 07:45:46.371304 18412 authenticator.cpp:318] Authentication success 3: I1213 07:45:46.371389 18432 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1213 07:45:46.371429 18434 authenticatee.cpp:299] Authentication success 3: I1213 07:45:46.371475 18421 master.cpp:8962] Successfully authenticated principal 'test-principal' at [email protected]:35223 3: I1213 07:45:46.371528 18413 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(230)@172.17.0.4:35223 3: I1213 07:45:46.371816 18412 sched.cpp:502] Successfully authenticated with master [email protected]:35223 3: I1213 07:45:46.371840 18412 sched.cpp:824] Sending SUBSCRIBE call to [email protected]:35223 3: I1213 07:45:46.372016 18412 sched.cpp:857] Will retry registration in 1.248117417secs if necessary 3: I1213 07:45:46.372262 18423 master.cpp:2957] Received SUBSCRIBE call for framework 'default' at [email protected]:35223 3: I1213 07:45:46.372288 18423 master.cpp:2274] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' write /dev/stdout: resource temporarily unavailable + docker rmi mesos-1513149368-14182 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]
