Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers,GLOG_v=1 MESOS_VERBOSE=1,centos:7,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4477

[Apache Jenkins Server <je...@builds.apache.org>]

See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4477/display/redirect?page=changes>

Changes:

[alexr] Revert "Added safe downcasts for Socket.".

------------------------------------------
[...truncated 26.80 MB...]
3: I1120 13:42:06.221009 16012 sched.cpp:1191] Stopping framework a7ad047c-b6fc-4296-930e-03628ec62f66-0000
3: I1120 13:42:06.221462 16004 master.cpp:8792] Processing TEARDOWN call for framework a7ad047c-b6fc-4296-930e-03628ec62f66-0000 (default) at scheduler-6ef5cca0-b9a7-4778-af47-f1e1753c0124@172.17.0.2:43730
3: I1120 13:42:06.221511 16004 master.cpp:8804] Removing framework a7ad047c-b6fc-4296-930e-03628ec62f66-0000 (default) at scheduler-6ef5cca0-b9a7-4778-af47-f1e1753c0124@172.17.0.2:43730
3: I1120 13:42:06.221525 16004 master.cpp:3331] Deactivating framework a7ad047c-b6fc-4296-930e-03628ec62f66-0000 (default) at scheduler-6ef5cca0-b9a7-4778-af47-f1e1753c0124@172.17.0.2:43730
3: I1120 13:42:06.221757 16009 hierarchical.cpp:419] Deactivated framework a7ad047c-b6fc-4296-930e-03628ec62f66-0000
3: I1120 13:42:06.221801 15993 slave.cpp:3267] Asked to shut down framework a7ad047c-b6fc-4296-930e-03628ec62f66-0000 by master@172.17.0.2:43730
3: I1120 13:42:06.221813 16004 master.cpp:9502] Updating the state of task 0 of framework a7ad047c-b6fc-4296-930e-03628ec62f66-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
3: I1120 13:42:06.221842 15993 slave.cpp:3292] Shutting down framework a7ad047c-b6fc-4296-930e-03628ec62f66-0000
3: I1120 13:42:06.221899 15993 slave.cpp:5874] Shutting down executor 'default' of framework a7ad047c-b6fc-4296-930e-03628ec62f66-0000 at executor(194)@172.17.0.2:43730
3: I1120 13:42:06.222093 16008 exec.cpp:435] Executor asked to shutdown
3: I1120 13:42:06.222131 16008 exec.cpp:450] Executor::shutdown took 16438ns
3: I1120 13:42:06.222303 16008 slave.cpp:5130] Got exited event for executor(194)@172.17.0.2:43730
3: I1120 13:42:06.222373 16004 master.cpp:9596] Removing task 0 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"}] of framework a7ad047c-b6fc-4296-930e-03628ec62f66-0000 on agent a7ad047c-b6fc-4296-930e-03628ec62f66-S0 at slave(744)@172.17.0.2:43730 (34399db4b2ed)
3: I1120 13:42:06.222571 16001 hierarchical.cpp:1132] Recovered cpus(allocated: *):0.1; mem(allocated: *):32 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: {}) on agent a7ad047c-b6fc-4296-930e-03628ec62f66-S0 from framework a7ad047c-b6fc-4296-930e-03628ec62f66-0000
3: I1120 13:42:06.222815 16004 master.cpp:9625] Removing executor 'default' with resources [] of framework a7ad047c-b6fc-4296-930e-03628ec62f66-0000 on agent a7ad047c-b6fc-4296-930e-03628ec62f66-S0 at slave(744)@172.17.0.2:43730 (34399db4b2ed)
3: I1120 13:42:06.223513 16002 hierarchical.cpp:358] Removed framework a7ad047c-b6fc-4296-930e-03628ec62f66-0000
3: I1120 13:42:06.223995 16007 slave.cpp:5539] Executor 'default' of framework a7ad047c-b6fc-4296-930e-03628ec62f66-0000 exited with status 0
3: I1120 13:42:06.224093 16007 slave.cpp:5643] Cleaning up executor 'default' of framework a7ad047c-b6fc-4296-930e-03628ec62f66-0000 at executor(194)@172.17.0.2:43730
3: W1120 13:42:06.224247 16010 master.cpp:7453] Ignoring unknown exited executor 'default' of framework a7ad047c-b6fc-4296-930e-03628ec62f66-0000 on agent a7ad047c-b6fc-4296-930e-03628ec62f66-S0 at slave(744)@172.17.0.2:43730 (34399db4b2ed)
3: I1120 13:42:06.224318 16010 gc.cpp:90] Scheduling '/tmp/ContentType_AgentAPITest_LaunchNestedContainerSessionAttachFailure_1_N1Ohmj/slaves/a7ad047c-b6fc-4296-930e-03628ec62f66-S0/frameworks/a7ad047c-b6fc-4296-930e-03628ec62f66-0000/executors/default/runs/2d002303-f023-4c0c-ac17-3820e7d8ca67' for gc 6.9999981198963days in the future
3: I1120 13:42:06.224462 16010 gc.cpp:90] Scheduling '/tmp/ContentType_AgentAPITest_LaunchNestedContainerSessionAttachFailure_1_N1Ohmj/slaves/a7ad047c-b6fc-4296-930e-03628ec62f66-S0/frameworks/a7ad047c-b6fc-4296-930e-03628ec62f66-0000/executors/default' for gc 6.9999981198963days in the future
3: I1120 13:42:06.224480 16007 slave.cpp:5750] Cleaning up framework a7ad047c-b6fc-4296-930e-03628ec62f66-0000
3: I1120 13:42:06.224561 16010 status_update_manager.cpp:285] Closing status update streams for framework a7ad047c-b6fc-4296-930e-03628ec62f66-0000
3: I1120 13:42:06.224686 16014 gc.cpp:90] Scheduling '/tmp/ContentType_AgentAPITest_LaunchNestedContainerSessionAttachFailure_1_N1Ohmj/slaves/a7ad047c-b6fc-4296-930e-03628ec62f66-S0/frameworks/a7ad047c-b6fc-4296-930e-03628ec62f66-0000' for gc 6.9999981198963days in the future
3: I1120 13:42:06.224997 15991 slave.cpp:883] Agent terminating
3: I1120 13:42:06.225203 15992 master.cpp:1309] Agent a7ad047c-b6fc-4296-930e-03628ec62f66-S0 at slave(744)@172.17.0.2:43730 (34399db4b2ed) disconnected
3: I1120 13:42:06.225239 15992 master.cpp:3368] Disconnecting agent a7ad047c-b6fc-4296-930e-03628ec62f66-S0 at slave(744)@172.17.0.2:43730 (34399db4b2ed)
3: I1120 13:42:06.225332 15992 master.cpp:3387] Deactivating agent a7ad047c-b6fc-4296-930e-03628ec62f66-S0 at slave(744)@172.17.0.2:43730 (34399db4b2ed)
3: I1120 13:42:06.225482 15994 hierarchical.cpp:697] Agent a7ad047c-b6fc-4296-930e-03628ec62f66-S0 deactivated
3: I1120 13:42:06.229084 15991 master.cpp:1151] Master terminating
3: I1120 13:42:06.229984 16000 hierarchical.cpp:633] Removed agent a7ad047c-b6fc-4296-930e-03628ec62f66-S0
3: [       OK ] ContentType/AgentAPITest.LaunchNestedContainerSessionAttachFailure/1 (72 ms)
3: [ RUN      ] ContentType/AgentAPITest.LaunchNestedContainerSession/0
3: I1120 13:42:06.238344 15991 cluster.cpp:162] Creating default 'local' authorizer
3: I1120 13:42:06.241267 16001 master.cpp:448] Master 96dec12a-2830-4273-b229-22ab82c9497a (34399db4b2ed) started on 172.17.0.2:43730
3: I1120 13:42:06.241289 16001 master.cpp:450] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1000secs" --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/R9LAyH/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/R9LAyH/master" --zk_session_timeout="10secs"
3: I1120 13:42:06.241557 16001 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1120 13:42:06.241564 16001 master.cpp:505] Master only allowing authenticated agents to register
3: I1120 13:42:06.241569 16001 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1120 13:42:06.241572 16001 credentials.hpp:37] Loading credentials for authentication from '/tmp/R9LAyH/credentials'
3: I1120 13:42:06.241842 16001 master.cpp:555] Using default 'crammd5' authenticator
3: I1120 13:42:06.241978 16001 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1120 13:42:06.242111 16001 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1120 13:42:06.242225 16001 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1120 13:42:06.242334 16001 master.cpp:634] Authorization enabled
3: I1120 13:42:06.242470 16002 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1120 13:42:06.242522 16013 whitelist_watcher.cpp:77] No whitelist given
3: I1120 13:42:06.245317 16003 master.cpp:2213] Elected as the leading master!
3: I1120 13:42:06.245342 16003 master.cpp:1693] Recovering from registrar
3: I1120 13:42:06.245498 16005 registrar.cpp:347] Recovering registrar
3: I1120 13:42:06.246053 16005 registrar.cpp:391] Successfully fetched the registry (0B) in 514816ns
3: I1120 13:42:06.246160 16005 registrar.cpp:495] Applied 1 operations in 29882ns; attempting to update the registry
3: I1120 13:42:06.246692 16005 registrar.cpp:552] Successfully updated the registry in 481792ns
3: I1120 13:42:06.246811 16005 registrar.cpp:424] Successfully recovered registrar
3: I1120 13:42:06.247146 15992 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1120 13:42:06.247186 16004 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: I1120 13:42:06.250074 15991 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1120 13:42:06.250576 15991 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1120 13:42:06.250684 15991 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1120 13:42:06.250712 15991 provisioner.cpp:255] Using default backend 'copy'
3: W1120 13:42:06.254530 15991 process.cpp:2754] Attempted to spawn already running process files@172.17.0.2:43730
3: I1120 13:42:06.254791 15991 cluster.cpp:448] Creating default 'local' authorizer
3: I1120 13:42:06.256822 15992 slave.cpp:262] Mesos agent started on (745)@172.17.0.2:43730
3: I1120 13:42:06.256842 15992 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/ContentType_AgentAPITest_LaunchNestedContainerSession_0_hCVKTT/store/appc" --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/ContentType_AgentAPITest_LaunchNestedContainerSession_0_hCVKTT/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/ContentType_AgentAPITest_LaunchNestedContainerSession_0_hCVKTT/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/ContentType_AgentAPITest_LaunchNestedContainerSession_0_hCVKTT/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/ContentType_AgentAPITest_LaunchNestedContainerSession_0_hCVKTT/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/ContentType_AgentAPITest_LaunchNestedContainerSession_0_hCVKTT" --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/ContentType_AgentAPITest_LaunchNestedContainerSession_0_OzhaJi" --zk_session_timeout="10secs"
3: I1120 13:42:06.257266 15992 credentials.hpp:86] Loading credential for authentication from '/tmp/ContentType_AgentAPITest_LaunchNestedContainerSession_0_hCVKTT/credential'
3: W1120 13:42:06.257407 15991 process.cpp:2754] Attempted to spawn already running process version@172.17.0.2:43730
3: I1120 13:42:06.257418 15992 slave.cpp:295] Agent using credential for: test-principal
3: I1120 13:42:06.257438 15992 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_AgentAPITest_LaunchNestedContainerSession_0_hCVKTT/http_credentials'
3: I1120 13:42:06.257706 15992 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1120 13:42:06.257854 15992 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1120 13:42:06.258239 15991 sched.cpp:232] Version: 1.5.0
3: I1120 13:42:06.258774 15993 sched.cpp:336] New master detected at master@172.17.0.2:43730
3: I1120 13:42:06.258960 15993 sched.cpp:396] Authenticating with master master@172.17.0.2:43730
3: I1120 13:42:06.258986 15993 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1120 13:42:06.259457 15998 authenticatee.cpp:121] Creating new client SASL connection
3: I1120 13:42:06.259340 15992 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: I1120 13:42:06.259572 15992 slave.cpp:601] Agent attributes: [  ]
3: I1120 13:42:06.259585 15992 slave.cpp:610] Agent hostname: 34399db4b2ed
3: I1120 13:42:06.259757 16005 status_update_manager.cpp:177] Pausing sending status updates
3: I1120 13:42:06.259822 15997 master.cpp:8285] Authenticating scheduler-df893ef7-920f-4b6a-8f84-f8c14533865a@172.17.0.2:43730
3: I1120 13:42:06.259956 15994 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1383)@172.17.0.2:43730
3: I1120 13:42:06.260221 16015 authenticator.cpp:98] Creating new server SASL connection
3: I1120 13:42:06.260457 16011 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1120 13:42:06.260478 16011 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1120 13:42:06.260586 15995 authenticator.cpp:204] Received SASL authentication start
3: I1120 13:42:06.260641 15995 authenticator.cpp:326] Authentication requires more steps
3: I1120 13:42:06.260746 16013 authenticatee.cpp:259] Received SASL authentication step
3: I1120 13:42:06.260884 16002 authenticator.cpp:232] Received SASL authentication step
3: I1120 13:42:06.260910 16002 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '34399db4b2ed' server FQDN: '34399db4b2ed' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1120 13:42:06.260920 16002 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1120 13:42:06.260949 16002 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1120 13:42:06.260968 16002 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '34399db4b2ed' server FQDN: '34399db4b2ed' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1120 13:42:06.260975 16002 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1120 13:42:06.260980 16002 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1120 13:42:06.260993 16002 authenticator.cpp:318] Authentication success
3: I1120 13:42:06.261085 16012 authenticatee.cpp:299] Authentication success
3: I1120 13:42:06.261167 16009 master.cpp:8315] Successfully authenticated principal 'test-principal' at scheduler-df893ef7-920f-4b6a-8f84-f8c14533865a@172.17.0.2:43730
3: I1120 13:42:06.261204 16003 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1383)@172.17.0.2:43730
3: I1120 13:42:06.261294 16014 state.cpp:64] Recovering state from '/tmp/ContentType_AgentAPITest_LaunchNestedContainerSession_0_OzhaJi/meta'
3: I1120 13:42:06.261456 16010 sched.cpp:502] Successfully authenticated with master master@172.17.0.2:43730
3: I1120 13:42:06.261476 16010 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.2:43730
3: I1120 13:42:06.261538 16014 status_update_manager.cpp:203] Recovering status update manager
3: I1120 13:42:06.261596 16010 sched.cpp:857] Will retry registration in 1.559219429secs if necessary
3: I1120 13:42:06.261718 15994 containerizer.cpp:662] Recovering containerizer
3: I1120 13:42:06.261744 16005 master.cpp:2961] Received SUBSCRIBE call for framework 'default' at scheduler-df893ef7-920f-4b6a-8f84-f8c14533865a@172.17.0.2:43730
3: I1120 13:42:06.261813 16005 master.cpp:2278] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
3: I1120 13:42:06.262244 16013 master.cpp:3041] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1120 13:42:06.262938 16001 hierarchical.cpp:306] Added framework 96dec12a-2830-4273-b229-22ab82c9497a-0000
3: I1120 13:42:06.263021 15993 sched.cpp:751] Framework registered with 96dec12a-2830-4273-b229-22ab82c9497a-0000
3: I1120 13:42:06.263063 16008 provisioner.cpp:416] Provisioner recovery complete
3: I1120 13:42:06.263093 15993 sched.cpp:765] Scheduler::registered took 31713ns
3: I1120 13:42:06.263120 16001 hierarchical.cpp:1457] Performed allocation for 0 agents in 68790ns
3: I1120 13:42:06.263371 16014 slave.cpp:6441] Finished recovery
3: I1120 13:42:06.264014 16006 status_update_manager.cpp:177] Pausing sending status updates
3: I1120 13:42:06.264019 16015 slave.cpp:1007] New master detected at master@172.17.0.2:43730
3: I1120 13:42:06.264112 16015 slave.cpp:1042] Detecting new master
3: I1120 13:42:06.265328 15995 slave.cpp:1069] Authenticating with master master@172.17.0.2:43730
3: I1120 13:42:06.265385 15995 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1120 13:42:06.265600 16007 authenticatee.cpp:121] Creating new client SASL connection
3: I1120 13:42:06.265836 16002 master.cpp:8285] Authenticating slave(745)@172.17.0.2:43730
3: I1120 13:42:06.265926 16004 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1384)@172.17.0.2:43730
3: I1120 13:42:06.266149 15994 authenticator.cpp:98] Creating new server SASL connection
3: I1120 13:42:06.266341 15992 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1120 13:42:06.266361 15992 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1120 13:42:06.266506 15996 authenticator.cpp:204] Received SASL authentication start
3: I1120 13:42:06.266613 15996 authenticator.cpp:326] Authentication requires more steps
3: I1120 13:42:06.266765 16000 authenticatee.cpp:259] Received SASL authentication step
3: I1120 13:42:06.266918 16000 authenticator.cpp:232] Received SASL authentication step
3: I1120 13:42:06.266961 16000 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '34399db4b2ed' server FQDN: '34399db4b2ed' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1120 13:42:06.266981 16000 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1120 13:42:06.267041 16000 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1120 13:42:06.267077 16000 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '34399db4b2ed' server FQDN: '34399db4b2ed' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1120 13:42:06.267087 16000 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1120 13:42:06.267092 16000 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1120 13:42:06.267105 16000 authenticator.cpp:318] Authentication success
3: I1120 13:42:06.267303 16012 authenticatee.cpp:299] Authentication success
3: I1120 13:42:06.267391 15999 master.cpp:8315] Successfully authenticated principal 'test-principal' at slave(745)@172.17.0.2:43730
3: I1120 13:42:06.267422 16000 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1384)@172.17.0.2:43730
3: I1120 13:42:06.267819 16001 slave.cpp:1161] Successfully authenticated with master master@172.17.0.2:43730
3: I1120 13:42:06.268033 16001 slave.cpp:1682] Will retry registration in 1.373604ms if necessary
3: I1120 13:42:06.268311 16010 master.cpp:6032] Received register agent message from slave(745)@172.17.0.2:43730 (34399db4b2ed)
3: I1120 13:42:06.268470 16010 master.cpp:3870] Authorizing agent with principal 'test-principal'
3: I1120 13:42:06.268832 15997 master.cpp:6092] Authorized registration of agent at slave(745)@172.17.0.2:43730 (34399db4b2ed)
3: I1120 13:42:06.268930 15997 master.cpp:6185] Registering agent at slave(745)@172.17.0.2:43730 (34399db4b2ed) with id 96dec12a-2830-4273-b229-22ab82c9497a-S0
3: I1120 13:42:06.269338 16005 registrar.cpp:495] Applied 1 operations in 58206ns; attempting to update the registry
3: I1120 13:42:06.269852 16005 registrar.cpp:552] Successfully updated the registry in 463872ns
3: I1120 13:42:06.270020 16007 master.cpp:6232] Admitted agent 96dec12a-2830-4273-b229-22ab82c9497a-S0 at slave(745)@172.17.0.2:43730 (34399db4b2ed)
3: I1120 13:42:06.270499 16002 slave.cpp:1682] Will retry registration in 13.64861ms if necessary
3: I1120 13:42:06.270543 16007 master.cpp:6263] Registered agent 96dec12a-2830-4273-b229-22ab82c9497a-S0 at slave(745)@172.17.0.2:43730 (34399db4b2ed) 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: I1120 13:42:06.270757 16002 slave.cpp:1207] Registered with master master@172.17.0.2:43730; given agent ID 96dec12a-2830-4273-b229-22ab82c9497a-S0
3: I1120 13:42:06.270843 15994 hierarchical.cpp:600] Added agent 96dec12a-2830-4273-b229-22ab82c9497a-S0 (34399db4b2ed) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
3: I1120 13:42:06.270880 15996 status_update_manager.cpp:184] Resuming sending status updates
3: I1120 13:42:06.271024 16007 master.cpp:6032] Received register agent message from slave(745)@172.17.0.2:43730 (34399db4b2ed)
3: I1120 13:42:06.271044 16002 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/ContentType_AgentAPITest_LaunchNestedContainerSession_0_OzhaJi/meta/slaves/96dec12a-2830-4273-b229-22ab82c9497a-S0/slave.info'
3: I1120 13:42:06.271138 16007 master.cpp:3870] Authorizing agent with principal 'test-principal'
3: I1120 13:42:06.271395 16002 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: I1120 13:42:06.271570 16002 master.cpp:7064] Received update of agent 96dec12a-2830-4273-b229-22ab82c9497a-S0 at slave(745)@172.17.0.2:43730 (34399db4b2ed) with total oversubscribed resources {}
3: I1120 13:42:06.271718 16002 master.cpp:7082] Ignoring update on agent 96dec12a-2830-4273-b229-22ab82c9497a-S0 at slave(745)@172.17.0.2:43730 (34399db4b2ed) as it reports no changes
3: I1120 13:42:06.271792 16002 master.cpp:6092] Authorized registration of agent at slave(745)@172.17.0.2:43730 (34399db4b2ed)
3: I1120 13:42:06.271855 16002 master.cpp:6163] Agent 96dec12a-2830-4273-b229-22ab82c9497a-S0 at slave(745)@172.17.0.2:43730 (34399db4b2ed) already registered, resending acknowledgement
3: I1120 13:42:06.271912 15994 hierarchical.cpp:1457] Performed allocation for 1 agents in 924458ns
3: W1120 13:42:06.272034 16013 slave.cpp:1262] Already registered with master master@172.17.0.2:43730
3: I1120 13:42:06.272102 16013 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: I1120 13:42:06.272621 16002 master.cpp:8115] Sending 1 offers to framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 (default) at scheduler-df893ef7-920f-4b6a-8f84-f8c14533865a@172.17.0.2:43730
3: I1120 13:42:06.272917 16002 master.cpp:7064] Received update of agent 96dec12a-2830-4273-b229-22ab82c9497a-S0 at slave(745)@172.17.0.2:43730 (34399db4b2ed) with total oversubscribed resources {}
3: I1120 13:42:06.273114 16002 master.cpp:7082] Ignoring update on agent 96dec12a-2830-4273-b229-22ab82c9497a-S0 at slave(745)@172.17.0.2:43730 (34399db4b2ed) as it reports no changes
3: I1120 13:42:06.273380 16009 sched.cpp:921] Scheduler::resourceOffers took 175380ns
3: I1120 13:42:06.275712 16014 master.cpp:10024] Removing offer 96dec12a-2830-4273-b229-22ab82c9497a-O0
3: I1120 13:42:06.275912 16014 master.cpp:4228] Processing ACCEPT call for offers: [ 96dec12a-2830-4273-b229-22ab82c9497a-O0 ] on agent 96dec12a-2830-4273-b229-22ab82c9497a-S0 at slave(745)@172.17.0.2:43730 (34399db4b2ed) for framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 (default) at scheduler-df893ef7-920f-4b6a-8f84-f8c14533865a@172.17.0.2:43730
3: I1120 13:42:06.276058 16014 master.cpp:3597] Authorizing framework principal 'test-principal' to launch task 270bccea-24c8-40df-916e-fc5f29917604
3: I1120 13:42:06.279320 16014 master.cpp:10770] Adding task 270bccea-24c8-40df-916e-fc5f29917604 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 96dec12a-2830-4273-b229-22ab82c9497a-S0 at slave(745)@172.17.0.2:43730 (34399db4b2ed)
3: I1120 13:42:06.280023 16014 master.cpp:4976] Launching task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 (default) at scheduler-df893ef7-920f-4b6a-8f84-f8c14533865a@172.17.0.2:43730 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 96dec12a-2830-4273-b229-22ab82c9497a-S0 at slave(745)@172.17.0.2:43730 (34399db4b2ed)
3: I1120 13:42:06.281057 16011 slave.cpp:1803] Got assigned task '270bccea-24c8-40df-916e-fc5f29917604' for framework 96dec12a-2830-4273-b229-22ab82c9497a-0000
3: I1120 13:42:06.281793 16011 slave.cpp:2071] Authorizing task '270bccea-24c8-40df-916e-fc5f29917604' for framework 96dec12a-2830-4273-b229-22ab82c9497a-0000
3: I1120 13:42:06.281858 16011 slave.cpp:7262] Authorizing framework principal 'test-principal' to launch task 270bccea-24c8-40df-916e-fc5f29917604
3: I1120 13:42:06.282543 15992 slave.cpp:2239] Launching task '270bccea-24c8-40df-916e-fc5f29917604' for framework 96dec12a-2830-4273-b229-22ab82c9497a-0000
3: I1120 13:42:06.283196 15992 paths.cpp:621] Trying to chown '/tmp/ContentType_AgentAPITest_LaunchNestedContainerSession_0_OzhaJi/slaves/96dec12a-2830-4273-b229-22ab82c9497a-S0/frameworks/96dec12a-2830-4273-b229-22ab82c9497a-0000/executors/270bccea-24c8-40df-916e-fc5f29917604/runs/b2a0b5e0-76ec-4001-8025-ae9a5799922e' to user 'mesos'
3: I1120 13:42:06.283479 15992 slave.cpp:7736] Launching executor '270bccea-24c8-40df-916e-fc5f29917604' of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"}] in work directory '/tmp/ContentType_AgentAPITest_LaunchNestedContainerSession_0_OzhaJi/slaves/96dec12a-2830-4273-b229-22ab82c9497a-S0/frameworks/96dec12a-2830-4273-b229-22ab82c9497a-0000/executors/270bccea-24c8-40df-916e-fc5f29917604/runs/b2a0b5e0-76ec-4001-8025-ae9a5799922e'
3: I1120 13:42:06.284200 15992 slave.cpp:2930] Launching container b2a0b5e0-76ec-4001-8025-ae9a5799922e for executor '270bccea-24c8-40df-916e-fc5f29917604' of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000
3: I1120 13:42:06.284561 16003 containerizer.cpp:1149] Starting container b2a0b5e0-76ec-4001-8025-ae9a5799922e
3: I1120 13:42:06.284617 15992 slave.cpp:2467] Queued task '270bccea-24c8-40df-916e-fc5f29917604' for executor '270bccea-24c8-40df-916e-fc5f29917604' of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000
3: I1120 13:42:06.284734 15992 slave.cpp:958] Successfully attached '/tmp/ContentType_AgentAPITest_LaunchNestedContainerSession_0_OzhaJi/slaves/96dec12a-2830-4273-b229-22ab82c9497a-S0/frameworks/96dec12a-2830-4273-b229-22ab82c9497a-0000/executors/270bccea-24c8-40df-916e-fc5f29917604/runs/b2a0b5e0-76ec-4001-8025-ae9a5799922e' to virtual path '/tmp/ContentType_AgentAPITest_LaunchNestedContainerSession_0_OzhaJi/slaves/96dec12a-2830-4273-b229-22ab82c9497a-S0/frameworks/96dec12a-2830-4273-b229-22ab82c9497a-0000/executors/270bccea-24c8-40df-916e-fc5f29917604/runs/latest'
3: I1120 13:42:06.284791 15992 slave.cpp:958] Successfully attached '/tmp/ContentType_AgentAPITest_LaunchNestedContainerSession_0_OzhaJi/slaves/96dec12a-2830-4273-b229-22ab82c9497a-S0/frameworks/96dec12a-2830-4273-b229-22ab82c9497a-0000/executors/270bccea-24c8-40df-916e-fc5f29917604/runs/b2a0b5e0-76ec-4001-8025-ae9a5799922e' to virtual path '/frameworks/96dec12a-2830-4273-b229-22ab82c9497a-0000/executors/270bccea-24c8-40df-916e-fc5f29917604/runs/latest'
3: I1120 13:42:06.284842 15992 slave.cpp:958] Successfully attached '/tmp/ContentType_AgentAPITest_LaunchNestedContainerSession_0_OzhaJi/slaves/96dec12a-2830-4273-b229-22ab82c9497a-S0/frameworks/96dec12a-2830-4273-b229-22ab82c9497a-0000/executors/270bccea-24c8-40df-916e-fc5f29917604/runs/b2a0b5e0-76ec-4001-8025-ae9a5799922e' to virtual path '/tmp/ContentType_AgentAPITest_LaunchNestedContainerSession_0_OzhaJi/slaves/96dec12a-2830-4273-b229-22ab82c9497a-S0/frameworks/96dec12a-2830-4273-b229-22ab82c9497a-0000/executors/270bccea-24c8-40df-916e-fc5f29917604/runs/b2a0b5e0-76ec-4001-8025-ae9a5799922e'
3: I1120 13:42:06.285101 16003 containerizer.cpp:2818] Transitioning the state of container b2a0b5e0-76ec-4001-8025-ae9a5799922e from PROVISIONING to PREPARING
3: I1120 13:42:06.290335 16010 containerizer.cpp:1768] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=\/mesos\/build\/src"],"shell":false,"value":"\/mesos\/build\/src\/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.2:43730"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/ContentType_AgentAPITest_LaunchNestedContainerSession_0_OzhaJi\/slaves\/96dec12a-2830-4273-b229-22ab82c9497a-S0\/frameworks\/96dec12a-2830-4273-b229-22ab82c9497a-0000\/executors\/270bccea-24c8-40df-916e-fc5f29917604\/runs\/b2a0b5e0-76ec-4001-8025-ae9a5799922e"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"270bccea-24c8-40df-916e-fc5f29917604"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"96dec12a-2830-4273-b229-22ab82c9497a-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"96dec12a-2830-4273-b229-22ab82c9497a-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(745)@172.17.0.2:43730"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/ContentType_AgentAPITest_LaunchNestedContainerSession_0_OzhaJi\/slaves\/96dec12a-2830-4273-b229-22ab82c9497a-S0\/frameworks\/96dec12a-2830-4273-b229-22ab82c9497a-0000\/executors\/270bccea-24c8-40df-916e-fc5f29917604\/runs\/b2a0b5e0-76ec-4001-8025-ae9a5799922e"}]},"task_environment":{},"user":"mesos","working_directory":"\/tmp\/ContentType_AgentAPITest_LaunchNestedContainerSession_0_OzhaJi\/slaves\/96dec12a-2830-4273-b229-22ab82c9497a-S0\/frameworks\/96dec12a-2830-4273-b229-22ab82c9497a-0000\/executors\/270bccea-24c8-40df-916e-fc5f29917604\/runs\/b2a0b5e0-76ec-4001-8025-ae9a5799922e"}" --pipe_read="9" --pipe_write="10" --runtime_directory="/tmp/ContentType_AgentAPITest_LaunchNestedContainerSession_0_hCVKTT/containers/b2a0b5e0-76ec-4001-8025-ae9a5799922e" --unshare_namespace_mnt="false"'
3: I1120 13:42:06.294209 16010 launcher.cpp:140] Forked child with pid '23466' for container 'b2a0b5e0-76ec-4001-8025-ae9a5799922e'
3: I1120 13:42:06.294908 16010 containerizer.cpp:2818] Transitioning the state of container b2a0b5e0-76ec-4001-8025-ae9a5799922e from PREPARING to ISOLATING
3: I1120 13:42:06.296648 16013 containerizer.cpp:2818] Transitioning the state of container b2a0b5e0-76ec-4001-8025-ae9a5799922e from ISOLATING to FETCHING
3: I1120 13:42:06.296885 15994 fetcher.cpp:379] Starting to fetch URIs for container: b2a0b5e0-76ec-4001-8025-ae9a5799922e, directory: /tmp/ContentType_AgentAPITest_LaunchNestedContainerSession_0_OzhaJi/slaves/96dec12a-2830-4273-b229-22ab82c9497a-S0/frameworks/96dec12a-2830-4273-b229-22ab82c9497a-0000/executors/270bccea-24c8-40df-916e-fc5f29917604/runs/b2a0b5e0-76ec-4001-8025-ae9a5799922e
3: I1120 13:42:06.297904 16000 containerizer.cpp:2818] Transitioning the state of container b2a0b5e0-76ec-4001-8025-ae9a5799922e from FETCHING to RUNNING
3: I1120 13:42:06.550140 15993 slave.cpp:4063] Got registration for executor '270bccea-24c8-40df-916e-fc5f29917604' of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 from executor(1)@172.17.0.2:44792
3: I1120 13:42:06.552678 16004 slave.cpp:2669] Sending queued task '270bccea-24c8-40df-916e-fc5f29917604' to executor '270bccea-24c8-40df-916e-fc5f29917604' of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 at executor(1)@172.17.0.2:44792
3: I1120 13:42:06.565542 16011 slave.cpp:4517] Handling status update TASK_STARTING (UUID: 73674d91-452d-497d-95e0-8225ac0404c5) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 from executor(1)@172.17.0.2:44792
3: I1120 13:42:06.567520 16007 status_update_manager.cpp:323] Received status update TASK_STARTING (UUID: 73674d91-452d-497d-95e0-8225ac0404c5) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000
3: I1120 13:42:06.567590 16007 status_update_manager.cpp:500] Creating StatusUpdate stream for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000
3: I1120 13:42:06.568262 16007 status_update_manager.cpp:377] Forwarding update TASK_STARTING (UUID: 73674d91-452d-497d-95e0-8225ac0404c5) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 to the agent
3: I1120 13:42:06.568500 16005 slave.cpp:4998] Forwarding the update TASK_STARTING (UUID: 73674d91-452d-497d-95e0-8225ac0404c5) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 to master@172.17.0.2:43730
3: I1120 13:42:06.568753 16005 slave.cpp:4892] Status update manager successfully handled status update TASK_STARTING (UUID: 73674d91-452d-497d-95e0-8225ac0404c5) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000
3: I1120 13:42:06.568802 16005 slave.cpp:4908] Sending acknowledgement for status update TASK_STARTING (UUID: 73674d91-452d-497d-95e0-8225ac0404c5) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 to executor(1)@172.17.0.2:44792
3: I1120 13:42:06.569070 15995 master.cpp:7247] Status update TASK_STARTING (UUID: 73674d91-452d-497d-95e0-8225ac0404c5) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 from agent 96dec12a-2830-4273-b229-22ab82c9497a-S0 at slave(745)@172.17.0.2:43730 (34399db4b2ed)
3: I1120 13:42:06.569133 15995 master.cpp:7309] Forwarding status update TASK_STARTING (UUID: 73674d91-452d-497d-95e0-8225ac0404c5) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000
3: I1120 13:42:06.569449 15995 master.cpp:9502] Updating the state of task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
3: I1120 13:42:06.569847 15992 sched.cpp:1029] Scheduler::statusUpdate took 156916ns
3: I1120 13:42:06.570354 15998 master.cpp:5791] Processing ACKNOWLEDGE call 73674d91-452d-497d-95e0-8225ac0404c5 for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 (default) at scheduler-df893ef7-920f-4b6a-8f84-f8c14533865a@172.17.0.2:43730 on agent 96dec12a-2830-4273-b229-22ab82c9497a-S0
3: I1120 13:42:06.570744 16013 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 73674d91-452d-497d-95e0-8225ac0404c5) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000
3: I1120 13:42:06.571074 16012 slave.cpp:3801] Status update manager successfully handled status update acknowledgement (UUID: 73674d91-452d-497d-95e0-8225ac0404c5) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000
3: I1120 13:42:06.572525 15993 process.cpp:3501] Handling HTTP event for process 'slave(745)' with path: '/slave(745)/api/v1'
3: I1120 13:42:06.573750 16014 http.cpp:1185] HTTP POST for /slave(745)/api/v1 from 172.17.0.2:48626
3: I1120 13:42:06.574450 16014 http.cpp:3116] Processing LAUNCH_NESTED_CONTAINER_SESSION call for container 'b2a0b5e0-76ec-4001-8025-ae9a5799922e.ffe1554e-9032-4bb3-b930-495460848b4c'
3: I1120 13:42:06.575704 15992 containerizer.cpp:1120] Trying to chown '/tmp/ContentType_AgentAPITest_LaunchNestedContainerSession_0_OzhaJi/slaves/96dec12a-2830-4273-b229-22ab82c9497a-S0/frameworks/96dec12a-2830-4273-b229-22ab82c9497a-0000/executors/270bccea-24c8-40df-916e-fc5f29917604/runs/b2a0b5e0-76ec-4001-8025-ae9a5799922e/containers/ffe1554e-9032-4bb3-b930-495460848b4c' to user 'mesos'
3: I1120 13:42:06.576107 15992 containerizer.cpp:1149] Starting container b2a0b5e0-76ec-4001-8025-ae9a5799922e.ffe1554e-9032-4bb3-b930-495460848b4c
3: I1120 13:42:06.576984 15992 containerizer.cpp:2818] Transitioning the state of container b2a0b5e0-76ec-4001-8025-ae9a5799922e.ffe1554e-9032-4bb3-b930-495460848b4c from PROVISIONING to PREPARING
3: I1120 13:42:06.579118 15998 switchboard.cpp:545] Launching 'mesos-io-switchboard' with flags '--heartbeat_interval="30secs" --help="false" --socket_address="/tmp/mesos-io-switchboard-e35ef096-0e45-4975-b570-44c7ac48ba25" --stderr_from_fd="19" --stderr_to_fd="2" --stdin_to_fd="16" --stdout_from_fd="17" --stdout_to_fd="1" --tty="false" --wait_for_connection="true"' for container b2a0b5e0-76ec-4001-8025-ae9a5799922e.ffe1554e-9032-4bb3-b930-495460848b4c
3: I1120 13:42:06.583230 15998 switchboard.cpp:575] Created I/O switchboard server (pid: 23494) listening on socket file '/tmp/mesos-io-switchboard-e35ef096-0e45-4975-b570-44c7ac48ba25' for container b2a0b5e0-76ec-4001-8025-ae9a5799922e.ffe1554e-9032-4bb3-b930-495460848b4c
3: I1120 13:42:06.584293 16009 slave.cpp:4517] Handling status update TASK_RUNNING (UUID: b298595f-7b18-4ede-be65-9be01d66c4b4) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 from executor(1)@172.17.0.2:44792
3: I1120 13:42:06.586555 15996 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: b298595f-7b18-4ede-be65-9be01d66c4b4) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000
3: I1120 13:42:06.586730 15996 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: b298595f-7b18-4ede-be65-9be01d66c4b4) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 to the agent
3: I1120 13:42:06.586539 16012 containerizer.cpp:1768] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"shell":true,"value":"printf output && printf error 1>&2"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.2:43730"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/ContentType_AgentAPITest_LaunchNestedContainerSession_0_OzhaJi\/slaves\/96dec12a-2830-4273-b229-22ab82c9497a-S0\/frameworks\/96dec12a-2830-4273-b229-22ab82c9497a-0000\/executors\/270bccea-24c8-40df-916e-fc5f29917604\/runs\/b2a0b5e0-76ec-4001-8025-ae9a5799922e"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"270bccea-24c8-40df-916e-fc5f29917604"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"96dec12a-2830-4273-b229-22ab82c9497a-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"96dec12a-2830-4273-b229-22ab82c9497a-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(745)@172.17.0.2:43730"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/ContentType_AgentAPITest_LaunchNestedContainerSession_0_OzhaJi\/slaves\/96dec12a-2830-4273-b229-22ab82c9497a-S0\/frameworks\/96dec12a-2830-4273-b229-22ab82c9497a-0000\/executors\/270bccea-24c8-40df-916e-fc5f29917604\/runs\/b2a0b5e0-76ec-4001-8025-ae9a5799922e"}]},"task_environment":{},"user":"mesos","working_directory":"\/tmp\/ContentType_AgentAPITest_LaunchNestedContainerSession_0_OzhaJi\/slaves\/96dec12a-2830-4273-b229-22ab82c9497a-S0\/frameworks\/96dec12a-2830-4273-b229-22ab82c9497a-0000\/executors\/270bccea-24c8-40df-916e-fc5f29917604\/runs\/b2a0b5e0-76ec-4001-8025-ae9a5799922e"}" --pipe_read="16" --pipe_write="17" --runtime_directory="/tmp/ContentType_AgentAPITest_LaunchNestedContainerSession_0_hCVKTT/containers/b2a0b5e0-76ec-4001-8025-ae9a5799922e/containers/ffe1554e-9032-4bb3-b930-495460848b4c" --unshare_namespace_mnt="false"'
3: I1120 13:42:06.586989 16015 slave.cpp:4998] Forwarding the update TASK_RUNNING (UUID: b298595f-7b18-4ede-be65-9be01d66c4b4) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 to master@172.17.0.2:43730
3: I1120 13:42:06.590235 16012 launcher.cpp:140] Forked child with pid '23495' for container 'b2a0b5e0-76ec-4001-8025-ae9a5799922e.ffe1554e-9032-4bb3-b930-495460848b4c'
3: I1120 13:42:06.590443 16015 slave.cpp:4892] Status update manager successfully handled status update TASK_RUNNING (UUID: b298595f-7b18-4ede-be65-9be01d66c4b4) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000
3: I1120 13:42:06.590548 16015 slave.cpp:4908] Sending acknowledgement for status update TASK_RUNNING (UUID: b298595f-7b18-4ede-be65-9be01d66c4b4) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 to executor(1)@172.17.0.2:44792
3: I1120 13:42:06.590749 16014 master.cpp:7247] Status update TASK_RUNNING (UUID: b298595f-7b18-4ede-be65-9be01d66c4b4) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 from agent 96dec12a-2830-4273-b229-22ab82c9497a-S0 at slave(745)@172.17.0.2:43730 (34399db4b2ed)
3: I1120 13:42:06.590821 16014 master.cpp:7309] Forwarding status update TASK_RUNNING (UUID: b298595f-7b18-4ede-be65-9be01d66c4b4) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000
3: I1120 13:42:06.590988 16012 containerizer.cpp:2818] Transitioning the state of container b2a0b5e0-76ec-4001-8025-ae9a5799922e.ffe1554e-9032-4bb3-b930-495460848b4c from PREPARING to ISOLATING
3: I1120 13:42:06.591145 16014 master.cpp:9502] Updating the state of task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
3: I1120 13:42:06.591538 16010 sched.cpp:1029] Scheduler::statusUpdate took 64711ns
3: I1120 13:42:06.592046 16012 containerizer.cpp:2818] Transitioning the state of container b2a0b5e0-76ec-4001-8025-ae9a5799922e.ffe1554e-9032-4bb3-b930-495460848b4c from ISOLATING to FETCHING
3: I1120 13:42:06.592021 16010 master.cpp:5791] Processing ACKNOWLEDGE call b298595f-7b18-4ede-be65-9be01d66c4b4 for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 (default) at scheduler-df893ef7-920f-4b6a-8f84-f8c14533865a@172.17.0.2:43730 on agent 96dec12a-2830-4273-b229-22ab82c9497a-S0
3: I1120 13:42:06.592329 16009 fetcher.cpp:379] Starting to fetch URIs for container: b2a0b5e0-76ec-4001-8025-ae9a5799922e.ffe1554e-9032-4bb3-b930-495460848b4c, directory: /tmp/ContentType_AgentAPITest_LaunchNestedContainerSession_0_OzhaJi/slaves/96dec12a-2830-4273-b229-22ab82c9497a-S0/frameworks/96dec12a-2830-4273-b229-22ab82c9497a-0000/executors/270bccea-24c8-40df-916e-fc5f29917604/runs/b2a0b5e0-76ec-4001-8025-ae9a5799922e/containers/ffe1554e-9032-4bb3-b930-495460848b4c
3: I1120 13:42:06.592669 15993 status_update_manager.cpp:395] Received status update acknowledgement (UUID: b298595f-7b18-4ede-be65-9be01d66c4b4) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000
3: I1120 13:42:06.593219 16008 slave.cpp:3801] Status update manager successfully handled status update acknowledgement (UUID: b298595f-7b18-4ede-be65-9be01d66c4b4) for task 270bccea-24c8-40df-916e-fc5f29917604 of framework 96dec12a-2830-4273-b229-22ab82c9497a-0000
3: I1120 13:42:06.593715 16002 containerizer.cpp:2818] Transitioning the state of container b2a0b5e0-76ec-4001-8025-ae9a5799922e.ffe1554e-9032-4bb3-b930-495460848b4c from FETCHING to RUNNING
3: I1120 13:42:06.594187 15998 http.cpp:3352] Processing ATTACH_CONTAINER_OUTPUT call for container 'b2a0b5e0-76ec-4001-8025-ae9a5799922e.ffe1554e-9032-4bb3-b930-495460848b4c'
3: I1120 13:42:06.755242 16012 http.cpp:3206] Received EOF attach response for b2a0b5e0-76ec-4001-8025-ae9a5799922e.ffe1554e-9032-4bb3-b930-495460848b4c
3: W1120 13:42:06.757290 16012 http.cpp:3221] Launch nested container session connection for container b2a0b5e0-76ec-4001-8025-ae9a5799922e.ffe1554e-9032-4bb3-b930-495460848b4c closed
3: I1120 13:42:06.757290 16009 containerizer.cpp:2254] Destroying container b2a0b5e0-76ec-4001-8025-ae9a5799922e.ffe1554e-9032-4bb3-b930-495460848b4c in RUNNING state
3: I1120 13:42:06.757398 16009 containerizer.cpp:2818] Transitioning the state of container b2a0b5e0-76ec-4001-8025-ae9a5799922e.ffe1554e-9032-4bb3-b930-495460848b4c from RUNNING to DESTROYING
3: I1120 13:42:06.757573 15991 sched.cpp:2009] Asked to stop the driver
3: I1120 13:42:06.757716 16007 sched.cpp:1191] Stopping framework 96dec12a-2830-4273-b229-22ab82c9497a-0000
3: I1120 13:42:06.757853 16009 launcher.cpp:156] Asked to destroy container b2a0b5e0-76ec-4001-8025-ae9a5799922e.ffe1554e-9032-4bb3-b930-495460848b4c
3: I1120 13:42:06.758107 15995 master.cpp:8792] Processing TEARDOWN call for framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 (default) at scheduler-df893ef7-920f-4b6a-8f84-f8c14533865a@172.17.0.2:43730
3: I1120 13:42:06.758147 15995 master.cpp:8804] Removing framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 (default) at scheduler-df893ef7-920f-4b6a-8f84-f8c14533865a@172.17.0.2:43730
3: I1120 13:42:06.758163 15995 master.cpp:3331] Deactivating framework 96dec12a-2830-4273-b229-22ab82c9497a-0000 (default) at scheduler-df893ef7-920f-4b6a-8f84-f8c14533865a@172.17.0.2:43730
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1511183309-10683
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user benjamin.hindman@gmail.com

Jenkins build is back to normal : Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers,GLOG_v=1 MESOS_VERBOSE=1,centos:7,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4478

[Apache Jenkins Server <je...@builds.apache.org>]

See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4478/display/redirect?page=changes>