You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2017/11/10 20:50:51 UTC
Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,centos:7,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4443
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=centos%3A7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4443/display/redirect?page=changes>
Changes:
[yujie.jay] Used `Master::_apply` consistently for all offer operations.
[alexr] Added context to agent processing calls.
[yujie.jay] Made the maintainer doc up-to-date.
------------------------------------------
[...truncated 20.90 MB...]
3: I1110 20:50:42.119194 17482 sched.cpp:947] Rescinded offer bf5375c1-13d4-4816-a37b-79f8dc10d3f8-O1
3: I1110 20:50:42.119282 17482 sched.cpp:958] Scheduler::offerRescinded took 56147ns
3: I1110 20:50:42.120065 17493 hierarchical.cpp:1125] Recovered ports(allocated: role):[31000-32000]; mem(allocated: role):2048; disk(allocated: role):1024; cpus(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):8; mem(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):2048; disk(allocated: role)(reservations: [(DYNAMIC,role,test-principal)])[persistence_id:container_path]:1024 (total: ports:[31000-32000]; mem:2048; disk:1024; cpus(reservations: [(DYNAMIC,role,test-principal)]):8; mem(reservations: [(DYNAMIC,role,test-principal)]):2048; disk(reservations: [(DYNAMIC,role,test-principal)])[persistence_id:container_path]:1024, allocated: {}) on agent bf5375c1-13d4-4816-a37b-79f8dc10d3f8-S0 from framework bf5375c1-13d4-4816-a37b-79f8dc10d3f8-0000
3: I1110 20:50:42.120841 17487 hierarchical.cpp:1450] Performed allocation for 1 agents in 192368ns
3: W1110 20:50:42.121999 17481 process.cpp:3178] Attempted to spawn already running process files@172.17.0.3:35939
3: I1110 20:50:42.122860 17494 slave.cpp:262] Mesos agent started on @172.17.0.3:35939
3: I1110 20:50:42.122884 17494 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/ReservationTest_CompatibleCheckpointedResourcesWithPersistentVolumes_1Wmc8L/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/ReservationTest_CompatibleCheckpointedResourcesWithPersistentVolumes_1Wmc8L/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/ReservationTest_CompatibleCheckpointedResourcesWithPersistentVolumes_1Wmc8L/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_secret_key="/tmp/ReservationTest_CompatibleCheckpointedResourcesWithPersistentVolumes_1Wmc8L/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ReservationTest_CompatibleCheckpointedResourcesWithPersistentVolumes_1Wmc8L/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/ReservationTest_CompatibleCheckpointedResourcesWithPersistentVolumes_1Wmc8L/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:12;mem:2048;disk:1024" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/ReservationTest_CompatibleCheckpointedResourcesWithPersistentVolumes_1Wmc8L" --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/ReservationTest_CompatibleCheckpointedResourcesWithPersistentVolumes_gEevh0" --zk_session_timeout="10secs"
3: I1110 20:50:42.123327 17494 credentials.hpp:86] Loading credential for authentication from '/tmp/ReservationTest_CompatibleCheckpointedResourcesWithPersistentVolumes_1Wmc8L/credential'
3: I1110 20:50:42.123473 17494 slave.cpp:295] Agent using credential for: test-principal
3: I1110 20:50:42.123489 17494 credentials.hpp:37] Loading credentials for authentication from '/tmp/ReservationTest_CompatibleCheckpointedResourcesWithPersistentVolumes_1Wmc8L/http_credentials'
3: I1110 20:50:42.123757 17494 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1110 20:50:42.123867 17494 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1110 20:50:42.124110 17494 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1110 20:50:42.124208 17494 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1110 20:50:42.124423 17494 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1110 20:50:42.124528 17494 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1110 20:50:42.125609 17494 slave.cpp:593] Agent resources: [{"name":"cpus","scalar":{"value":12.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":2048.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1110 20:50:42.125808 17494 slave.cpp:601] Agent attributes: [ ]
3: I1110 20:50:42.125820 17494 slave.cpp:610] Agent hostname: 40e8ef4cee13
3: I1110 20:50:42.125939 17484 status_update_manager.cpp:177] Pausing sending status updates
3: I1110 20:50:42.127429 17489 state.cpp:64] Recovering state from '/tmp/ReservationTest_CompatibleCheckpointedResourcesWithPersistentVolumes_gEevh0/meta'
3: I1110 20:50:42.128172 17489 state.cpp:96] Agent host rebooted
3: I1110 20:50:42.128710 17492 hierarchical.cpp:1450] Performed allocation for 1 agents in 194471ns
3: W1110 20:50:42.129779 17497 slave.cpp:6245] Falling back to recover as a new agent due to error: Incompatible agent info detected.
3: ------------------------------------------------------------
3: Old agent info:
3: hostname: "40e8ef4cee13"
3: resources {
3: name: "cpus"
3: type: SCALAR
3: scalar {
3: value: 8
3: }
3: }
3: resources {
3: name: "mem"
3: type: SCALAR
3: scalar {
3: value: 4096
3: }
3: }
3: resources {
3: name: "disk"
3: type: SCALAR
3: scalar {
3: value: 2048
3: }
3: }
3: resources {
3: name: "ports"
3: type: RANGES
3: ranges {
3: range {
3: begin: 31000
3: end: 32000
3: }
3: }
3: }
3: id {
3: value: "bf5375c1-13d4-4816-a37b-79f8dc10d3f8-S0"
3: }
3: checkpoint: true
3: port: 35939
3:
3: ------------------------------------------------------------
3: New agent info:
3: hostname: "40e8ef4cee13"
3: resources {
3: name: "cpus"
3: type: SCALAR
3: scalar {
3: value: 12
3: }
3: }
3: resources {
3: name: "mem"
3: type: SCALAR
3: scalar {
3: value: 2048
3: }
3: }
3: resources {
3: name: "disk"
3: type: SCALAR
3: scalar {
3: value: 1024
3: }
3: }
3: resources {
3: name: "ports"
3: type: RANGES
3: ranges {
3: range {
3: begin: 31000
3: end: 32000
3: }
3: }
3: }
3: checkpoint: true
3: port: 35939
3:
3: ------------------------------------------------------------
3: I1110 20:50:42.130033 17497 status_update_manager.cpp:203] Recovering status update manager
3: I1110 20:50:42.130779 17481 slave.cpp:883] Agent terminating
3: I1110 20:50:42.130888 17481 sched.cpp:2009] Asked to stop the driver
3: I1110 20:50:42.130954 17494 sched.cpp:1191] Stopping framework bf5375c1-13d4-4816-a37b-79f8dc10d3f8-0000
3: I1110 20:50:42.131206 17492 master.cpp:8793] Processing TEARDOWN call for framework bf5375c1-13d4-4816-a37b-79f8dc10d3f8-0000 (default) at scheduler-33e1d38c-0884-40b5-bf35-591886ed132f@172.17.0.3:35939
3: I1110 20:50:42.131240 17492 master.cpp:8805] Removing framework bf5375c1-13d4-4816-a37b-79f8dc10d3f8-0000 (default) at scheduler-33e1d38c-0884-40b5-bf35-591886ed132f@172.17.0.3:35939
3: I1110 20:50:42.131254 17492 master.cpp:3332] Deactivating framework bf5375c1-13d4-4816-a37b-79f8dc10d3f8-0000 (default) at scheduler-33e1d38c-0884-40b5-bf35-591886ed132f@172.17.0.3:35939
3: I1110 20:50:42.131379 17489 hierarchical.cpp:412] Deactivated framework bf5375c1-13d4-4816-a37b-79f8dc10d3f8-0000
3: I1110 20:50:42.132108 17483 hierarchical.cpp:355] Removed framework bf5375c1-13d4-4816-a37b-79f8dc10d3f8-0000
3: I1110 20:50:42.137411 17482 hierarchical.cpp:1450] Performed allocation for 1 agents in 191794ns
3: I1110 20:50:42.138120 17481 master.cpp:1151] Master terminating
3: I1110 20:50:42.139106 17497 hierarchical.cpp:626] Removed agent bf5375c1-13d4-4816-a37b-79f8dc10d3f8-S0
3: [ OK ] ReservationTest.CompatibleCheckpointedResourcesWithPersistentVolumes (83 ms)
3: [ RUN ] ReservationTest.IncompatibleCheckpointedResources
3: I1110 20:50:42.145748 17481 cluster.cpp:162] Creating default 'local' authorizer
3: I1110 20:50:42.149010 17486 master.cpp:448] Master 5b66f4bb-f1a6-4396-bb9d-f8400942a29f (40e8ef4cee13) started on 172.17.0.3:35939
3: I1110 20:50:42.149029 17486 master.cpp:450] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="5ms" --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/E4bVQD/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" --roles="role" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/E4bVQD/master" --zk_session_timeout="10secs"
3: I1110 20:50:42.149288 17486 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1110 20:50:42.149296 17486 master.cpp:505] Master only allowing authenticated agents to register
3: I1110 20:50:42.149300 17486 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1110 20:50:42.149305 17486 credentials.hpp:37] Loading credentials for authentication from '/tmp/E4bVQD/credentials'
3: I1110 20:50:42.149538 17486 master.cpp:555] Using default 'crammd5' authenticator
3: I1110 20:50:42.149657 17486 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1110 20:50:42.149770 17486 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1110 20:50:42.149879 17486 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1110 20:50:42.150001 17486 master.cpp:634] Authorization enabled
3: W1110 20:50:42.150013 17486 master.cpp:697] The '--roles' flag is deprecated. This flag will be removed in the future. See the Mesos 0.27 upgrade notes for more information
3: I1110 20:50:42.150238 17487 whitelist_watcher.cpp:77] No whitelist given
3: I1110 20:50:42.150326 17490 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1110 20:50:42.152819 17484 master.cpp:2213] Elected as the leading master!
3: I1110 20:50:42.152851 17484 master.cpp:1693] Recovering from registrar
3: I1110 20:50:42.153017 17493 registrar.cpp:347] Recovering registrar
3: I1110 20:50:42.153511 17493 registrar.cpp:391] Successfully fetched the registry (0B) in 461056ns
3: I1110 20:50:42.153590 17493 registrar.cpp:495] Applied 1 operations in 21545ns; attempting to update the registry
3: I1110 20:50:42.154021 17493 registrar.cpp:552] Successfully updated the registry in 391936ns
3: I1110 20:50:42.154119 17493 registrar.cpp:424] Successfully recovered registrar
3: I1110 20:50:42.154453 17492 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1110 20:50:42.154580 17490 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: I1110 20:50:42.157116 17484 hierarchical.cpp:1450] Performed allocation for 0 agents in 40210ns
3: W1110 20:50:42.160051 17481 process.cpp:3178] Attempted to spawn already running process files@172.17.0.3:35939
3: I1110 20:50:42.160858 17493 slave.cpp:262] Mesos agent started on @172.17.0.3:35939
3: W1110 20:50:42.161154 17481 process.cpp:3178] Attempted to spawn already running process version@172.17.0.3:35939
3: I1110 20:50:42.160878 17493 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/ReservationTest_IncompatibleCheckpointedResources_fVVa0b/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/ReservationTest_IncompatibleCheckpointedResources_fVVa0b/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/ReservationTest_IncompatibleCheckpointedResources_fVVa0b/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_secret_key="/tmp/ReservationTest_IncompatibleCheckpointedResources_fVVa0b/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ReservationTest_IncompatibleCheckpointedResources_fVVa0b/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/ReservationTest_IncompatibleCheckpointedResources_fVVa0b/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:8;mem:4096" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/ReservationTest_IncompatibleCheckpointedResources_fVVa0b" --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/ReservationTest_IncompatibleCheckpointedResources_SlvxVp" --zk_session_timeout="10secs"
3: I1110 20:50:42.161286 17493 credentials.hpp:86] Loading credential for authentication from '/tmp/ReservationTest_IncompatibleCheckpointedResources_fVVa0b/credential'
3: I1110 20:50:42.161449 17493 slave.cpp:295] Agent using credential for: test-principal
3: I1110 20:50:42.161468 17493 credentials.hpp:37] Loading credentials for authentication from '/tmp/ReservationTest_IncompatibleCheckpointedResources_fVVa0b/http_credentials'
3: I1110 20:50:42.161758 17493 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1110 20:50:42.161864 17493 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1110 20:50:42.162076 17493 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1110 20:50:42.162223 17493 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1110 20:50:42.162446 17493 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1110 20:50:42.162456 17481 sched.cpp:232] Version: 1.5.0
3: I1110 20:50:42.162556 17493 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1110 20:50:42.163018 17489 sched.cpp:336] New master detected at master@172.17.0.3:35939
3: I1110 20:50:42.163142 17489 sched.cpp:396] Authenticating with master master@172.17.0.3:35939
3: I1110 20:50:42.163161 17489 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1110 20:50:42.163424 17496 authenticatee.cpp:121] Creating new client SASL connection
3: I1110 20:50:42.163666 17484 master.cpp:8286] Authenticating scheduler-cd63ea06-9812-4760-b979-a30e15530e4c@172.17.0.3:35939
3: I1110 20:50:42.163786 17487 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1073)@172.17.0.3:35939
3: I1110 20:50:42.163730 17493 slave.cpp:593] Agent resources: [{"name":"cpus","scalar":{"value":8.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":4096.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":3701220.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1110 20:50:42.163964 17493 slave.cpp:601] Agent attributes: [ ]
3: I1110 20:50:42.163976 17493 slave.cpp:610] Agent hostname: 40e8ef4cee13
3: I1110 20:50:42.164095 17485 authenticator.cpp:98] Creating new server SASL connection
3: I1110 20:50:42.164106 17495 status_update_manager.cpp:177] Pausing sending status updates
3: I1110 20:50:42.164275 17492 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1110 20:50:42.164299 17492 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1110 20:50:42.164394 17485 authenticator.cpp:204] Received SASL authentication start
3: I1110 20:50:42.164439 17485 authenticator.cpp:326] Authentication requires more steps
3: I1110 20:50:42.164499 17488 hierarchical.cpp:1450] Performed allocation for 0 agents in 40505ns
3: I1110 20:50:42.164551 17485 authenticatee.cpp:259] Received SASL authentication step
3: I1110 20:50:42.164674 17497 authenticator.cpp:232] Received SASL authentication step
3: I1110 20:50:42.164702 17497 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '40e8ef4cee13' server FQDN: '40e8ef4cee13' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1110 20:50:42.164712 17497 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1110 20:50:42.164743 17497 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1110 20:50:42.164760 17497 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '40e8ef4cee13' server FQDN: '40e8ef4cee13' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1110 20:50:42.164772 17497 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1110 20:50:42.164779 17497 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1110 20:50:42.164793 17497 authenticator.cpp:318] Authentication success
3: I1110 20:50:42.164863 17489 authenticatee.cpp:299] Authentication success
3: I1110 20:50:42.165076 17484 master.cpp:8316] Successfully authenticated principal 'test-principal' at scheduler-cd63ea06-9812-4760-b979-a30e15530e4c@172.17.0.3:35939
3: I1110 20:50:42.165098 17495 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1073)@172.17.0.3:35939
3: I1110 20:50:42.165187 17491 sched.cpp:502] Successfully authenticated with master master@172.17.0.3:35939
3: I1110 20:50:42.165208 17491 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.3:35939
3: I1110 20:50:42.165325 17491 sched.cpp:857] Will retry registration in 566.889327ms if necessary
3: I1110 20:50:42.165508 17485 master.cpp:2962] Received SUBSCRIBE call for framework 'default' at scheduler-cd63ea06-9812-4760-b979-a30e15530e4c@172.17.0.3:35939
3: I1110 20:50:42.165547 17493 state.cpp:64] Recovering state from '/tmp/ReservationTest_IncompatibleCheckpointedResources_SlvxVp/meta'
3: I1110 20:50:42.165594 17485 master.cpp:2278] Authorizing framework principal 'test-principal' to receive offers for roles '{ role }'
3: I1110 20:50:42.165781 17485 status_update_manager.cpp:203] Recovering status update manager
3: I1110 20:50:42.166021 17487 master.cpp:3042] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1110 20:50:42.166175 17488 slave.cpp:6422] Finished recovery
3: I1110 20:50:42.166563 17482 sched.cpp:751] Framework registered with 5b66f4bb-f1a6-4396-bb9d-f8400942a29f-0000
3: I1110 20:50:42.166607 17482 sched.cpp:765] Scheduler::registered took 23006ns
3: I1110 20:50:42.166715 17492 hierarchical.cpp:303] Added framework 5b66f4bb-f1a6-4396-bb9d-f8400942a29f-0000
3: I1110 20:50:42.166877 17485 status_update_manager.cpp:177] Pausing sending status updates
3: I1110 20:50:42.166880 17488 slave.cpp:1007] New master detected at master@172.17.0.3:35939
3: I1110 20:50:42.166932 17488 slave.cpp:1042] Detecting new master
3: I1110 20:50:42.166960 17492 hierarchical.cpp:1450] Performed allocation for 0 agents in 135974ns
3: I1110 20:50:42.172484 17496 hierarchical.cpp:1450] Performed allocation for 0 agents in 46587ns
3: I1110 20:50:42.176684 17489 slave.cpp:1069] Authenticating with master master@172.17.0.3:35939
3: I1110 20:50:42.176736 17489 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1110 20:50:42.176913 17486 authenticatee.cpp:121] Creating new client SASL connection
3: I1110 20:50:42.177132 17483 master.cpp:8286] Authenticating (596)@172.17.0.3:35939
3: I1110 20:50:42.177230 17493 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1074)@172.17.0.3:35939
3: I1110 20:50:42.177531 17484 authenticator.cpp:98] Creating new server SASL connection
3: I1110 20:50:42.177820 17484 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1110 20:50:42.177847 17484 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1110 20:50:42.177958 17484 authenticator.cpp:204] Received SASL authentication start
3: I1110 20:50:42.178010 17484 authenticator.cpp:326] Authentication requires more steps
3: I1110 20:50:42.178117 17484 authenticatee.cpp:259] Received SASL authentication step
3: I1110 20:50:42.178236 17484 authenticator.cpp:232] Received SASL authentication step
3: I1110 20:50:42.178267 17484 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '40e8ef4cee13' server FQDN: '40e8ef4cee13' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1110 20:50:42.178277 17484 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1110 20:50:42.178310 17484 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1110 20:50:42.178330 17484 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '40e8ef4cee13' server FQDN: '40e8ef4cee13' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1110 20:50:42.178354 17484 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1110 20:50:42.178361 17484 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1110 20:50:42.178375 17484 authenticator.cpp:318] Authentication success
3: I1110 20:50:42.178483 17497 authenticatee.cpp:299] Authentication success
3: I1110 20:50:42.178580 17494 master.cpp:8316] Successfully authenticated principal 'test-principal' at (596)@172.17.0.3:35939
3: I1110 20:50:42.178592 17485 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1074)@172.17.0.3:35939
3: I1110 20:50:42.178736 17492 slave.cpp:1161] Successfully authenticated with master master@172.17.0.3:35939
3: I1110 20:50:42.178939 17492 slave.cpp:1682] Will retry registration in 7.275592ms if necessary
3: I1110 20:50:42.179100 17486 master.cpp:6033] Received register agent message from (596)@172.17.0.3:35939 (40e8ef4cee13)
3: I1110 20:50:42.179204 17486 master.cpp:3871] Authorizing agent with principal 'test-principal'
3: I1110 20:50:42.179498 17493 master.cpp:6093] Authorized registration of agent at (596)@172.17.0.3:35939 (40e8ef4cee13)
3: I1110 20:50:42.179584 17493 master.cpp:6186] Registering agent at (596)@172.17.0.3:35939 (40e8ef4cee13) with id 5b66f4bb-f1a6-4396-bb9d-f8400942a29f-S0
3: I1110 20:50:42.180042 17487 registrar.cpp:495] Applied 1 operations in 73923ns; attempting to update the registry
3: I1110 20:50:42.180706 17484 registrar.cpp:552] Successfully updated the registry in 598016ns
3: I1110 20:50:42.181002 17494 master.cpp:6233] Admitted agent 5b66f4bb-f1a6-4396-bb9d-f8400942a29f-S0 at (596)@172.17.0.3:35939 (40e8ef4cee13)
3: I1110 20:50:42.181318 17496 hierarchical.cpp:1450] Performed allocation for 0 agents in 79573ns
3: I1110 20:50:42.181768 17485 slave.cpp:1207] Registered with master master@172.17.0.3:35939; given agent ID 5b66f4bb-f1a6-4396-bb9d-f8400942a29f-S0
3: I1110 20:50:42.181859 17486 status_update_manager.cpp:184] Resuming sending status updates
3: I1110 20:50:42.181694 17494 master.cpp:6264] Registered agent 5b66f4bb-f1a6-4396-bb9d-f8400942a29f-S0 at (596)@172.17.0.3:35939 (40e8ef4cee13) with [{"name":"cpus","scalar":{"value":8.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":4096.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":3701220.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1110 20:50:42.181972 17489 hierarchical.cpp:593] Added agent 5b66f4bb-f1a6-4396-bb9d-f8400942a29f-S0 (40e8ef4cee13) with cpus:8; mem:4096; disk:3701220; ports:[31000-32000] (allocated: {})
3: I1110 20:50:42.182065 17485 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/ReservationTest_IncompatibleCheckpointedResources_SlvxVp/meta/slaves/5b66f4bb-f1a6-4396-bb9d-f8400942a29f-S0/slave.info'
3: I1110 20:50:42.182973 17489 hierarchical.cpp:1450] Performed allocation for 1 agents in 848558ns
3: I1110 20:50:42.183444 17483 master.cpp:8116] Sending 1 offers to framework 5b66f4bb-f1a6-4396-bb9d-f8400942a29f-0000 (default) at scheduler-cd63ea06-9812-4760-b979-a30e15530e4c@172.17.0.3:35939
3: I1110 20:50:42.183943 17493 sched.cpp:921] Scheduler::resourceOffers took 142492ns
3: I1110 20:50:42.185873 17491 master.cpp:10016] Removing offer 5b66f4bb-f1a6-4396-bb9d-f8400942a29f-O0
3: I1110 20:50:42.186018 17491 master.cpp:4229] Processing ACCEPT call for offers: [ 5b66f4bb-f1a6-4396-bb9d-f8400942a29f-O0 ] on agent 5b66f4bb-f1a6-4396-bb9d-f8400942a29f-S0 at (596)@172.17.0.3:35939 (40e8ef4cee13) for framework 5b66f4bb-f1a6-4396-bb9d-f8400942a29f-0000 (default) at scheduler-cd63ea06-9812-4760-b979-a30e15530e4c@172.17.0.3:35939
3: I1110 20:50:42.186187 17491 master.cpp:3656] Authorizing principal 'test-principal' to reserve resources '[{"allocation_info":{"role":"role"},"name":"cpus","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":8.0},"type":"SCALAR"},{"allocation_info":{"role":"role"},"name":"mem","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
3: I1110 20:50:42.188009 17491 master.cpp:4562] Applying RESERVE operation for resources [{"allocation_info":{"role":"role"},"name":"cpus","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":8.0},"type":"SCALAR"},{"allocation_info":{"role":"role"},"name":"mem","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}] from framework 5b66f4bb-f1a6-4396-bb9d-f8400942a29f-0000 (default) at scheduler-cd63ea06-9812-4760-b979-a30e15530e4c@172.17.0.3:35939 to agent 5b66f4bb-f1a6-4396-bb9d-f8400942a29f-S0 at (596)@172.17.0.3:35939 (40e8ef4cee13)
3: I1110 20:50:42.188853 17491 master.cpp:9961] Sending updated checkpointed resources cpus(reservations: [(DYNAMIC,role,test-principal)]):8; mem(reservations: [(DYNAMIC,role,test-principal)]):2048 to agent 5b66f4bb-f1a6-4396-bb9d-f8400942a29f-S0 at (596)@172.17.0.3:35939 (40e8ef4cee13)
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1510344711-13766
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user yujie.jay@gmail.com
Jenkins build is back to normal : Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,centos:7,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4446
Posted by 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%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4446/display/redirect>
Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,centos:7,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4445
Posted by 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%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4445/display/redirect>
------------------------------------------
[...truncated 16.74 MB...]
3: I1111 06:54:52.505245 18231 authenticator.cpp:98] Creating new server SASL connection
3: I1111 06:54:52.505419 18218 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1111 06:54:52.505442 18218 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1111 06:54:52.505537 18229 authenticator.cpp:204] Received SASL authentication start
3: I1111 06:54:52.505578 18229 authenticator.cpp:326] Authentication requires more steps
3: I1111 06:54:52.505661 18226 authenticatee.cpp:259] Received SASL authentication step
3: I1111 06:54:52.505762 18226 authenticator.cpp:232] Received SASL authentication step
3: I1111 06:54:52.505791 18226 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '02e3ced3c06a' server FQDN: '02e3ced3c06a' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1111 06:54:52.505808 18226 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1111 06:54:52.505838 18226 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1111 06:54:52.505867 18226 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '02e3ced3c06a' server FQDN: '02e3ced3c06a' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1111 06:54:52.505879 18226 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1111 06:54:52.505889 18226 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1111 06:54:52.505908 18226 authenticator.cpp:318] Authentication success
3: I1111 06:54:52.505986 18217 authenticatee.cpp:299] Authentication success
3: I1111 06:54:52.506022 18224 master.cpp:8316] Successfully authenticated principal 'test-principal' at slave(394)@172.17.0.4:33387
3: I1111 06:54:52.506047 18213 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(807)@172.17.0.4:33387
3: I1111 06:54:52.506222 18228 slave.cpp:1161] Successfully authenticated with master master@172.17.0.4:33387
3: I1111 06:54:52.506451 18228 slave.cpp:1682] Will retry registration in 16.56977ms if necessary
3: I1111 06:54:52.506618 18219 master.cpp:6033] Received register agent message from slave(394)@172.17.0.4:33387 (02e3ced3c06a)
3: I1111 06:54:52.506734 18219 master.cpp:3871] Authorizing agent with principal 'test-principal'
3: I1111 06:54:52.507071 18215 master.cpp:6093] Authorized registration of agent at slave(394)@172.17.0.4:33387 (02e3ced3c06a)
3: I1111 06:54:52.507172 18215 master.cpp:6186] Registering agent at slave(394)@172.17.0.4:33387 (02e3ced3c06a) with id 60131ef2-deaa-4674-89cc-679b7615f18d-S0
3: I1111 06:54:52.507575 18216 registrar.cpp:495] Applied 1 operations in 53456ns; attempting to update the registry
3: I1111 06:54:52.508088 18216 registrar.cpp:552] Successfully updated the registry in 461824ns
3: I1111 06:54:52.508268 18222 master.cpp:6233] Admitted agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a)
3: I1111 06:54:52.508901 18229 slave.cpp:1207] Registered with master master@172.17.0.4:33387; given agent ID 60131ef2-deaa-4674-89cc-679b7615f18d-S0
3: I1111 06:54:52.508983 18223 status_update_manager.cpp:184] Resuming sending status updates
3: I1111 06:54:52.508832 18222 master.cpp:6264] Registered agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a) with [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":367489.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1111 06:54:52.509124 18231 hierarchical.cpp:593] Added agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 (02e3ced3c06a) with cpus:2; mem:1024; disk:367489; ports:[31000-32000] (allocated: {})
3: I1111 06:54:52.509220 18229 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/MasterTest_MasterFailoverLongLivedExecutor_Mpz3TH/meta/slaves/60131ef2-deaa-4674-89cc-679b7615f18d-S0/slave.info'
3: I1111 06:54:52.509568 18229 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: I1111 06:54:52.509743 18226 master.cpp:7065] Received update of agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a) with total oversubscribed resources {}
3: I1111 06:54:52.509901 18226 master.cpp:7083] Ignoring update on agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a) as it reports no changes
3: I1111 06:54:52.510236 18231 hierarchical.cpp:1450] Performed allocation for 1 agents in 968733ns
3: I1111 06:54:52.510704 18217 master.cpp:8116] Sending 1 offers to framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 (default) at scheduler-5ab31fb3-f7b1-4382-b0fc-4b36354f41f6@172.17.0.4:33387
3: I1111 06:54:52.511195 18224 sched.cpp:921] Scheduler::resourceOffers took 101147ns
3: I1111 06:54:52.512800 18232 master.cpp:10016] Removing offer 60131ef2-deaa-4674-89cc-679b7615f18d-O0
3: I1111 06:54:52.512936 18232 master.cpp:4229] Processing ACCEPT call for offers: [ 60131ef2-deaa-4674-89cc-679b7615f18d-O0 ] on agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a) for framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 (default) at scheduler-5ab31fb3-f7b1-4382-b0fc-4b36354f41f6@172.17.0.4:33387
3: I1111 06:54:52.513015 18232 master.cpp:3598] Authorizing framework principal 'test-principal' to launch task 1
3: W1111 06:54:52.514765 18232 validation.cpp:1404] Executor 'default' for task '1' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
3: W1111 06:54:52.514794 18232 validation.cpp:1416] Executor 'default' for task '1' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
3: I1111 06:54:52.515153 18232 master.cpp:10762] Adding task 1 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] on agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a)
3: I1111 06:54:52.515481 18232 master.cpp:4977] Launching task 1 of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 (default) at scheduler-5ab31fb3-f7b1-4382-b0fc-4b36354f41f6@172.17.0.4:33387 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] on agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a)
3: I1111 06:54:52.515949 18233 slave.cpp:1803] Got assigned task '1' for framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: I1111 06:54:52.516569 18233 slave.cpp:2071] Authorizing task '1' for framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: I1111 06:54:52.516561 18227 hierarchical.cpp:1125] Recovered cpus(allocated: *):1; mem(allocated: *):512; disk(allocated: *):367489; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:367489; ports:[31000-32000], allocated: cpus(allocated: *):1; mem(allocated: *):512) on agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 from framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: I1111 06:54:52.516620 18233 slave.cpp:7030] Authorizing framework principal 'test-principal' to launch task 1
3: I1111 06:54:52.516629 18227 hierarchical.cpp:1171] Framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 filtered agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 for 5secs
3: I1111 06:54:52.517240 18218 slave.cpp:2239] Launching task '1' for framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: I1111 06:54:52.517884 18218 paths.cpp:605] Trying to chown '/tmp/MasterTest_MasterFailoverLongLivedExecutor_Mpz3TH/slaves/60131ef2-deaa-4674-89cc-679b7615f18d-S0/frameworks/60131ef2-deaa-4674-89cc-679b7615f18d-0000/executors/default/runs/96987039-3c59-4b1a-9e93-acd678f3570f' to user 'mesos'
3: I1111 06:54:52.518103 18218 slave.cpp:7504] Launching executor 'default' of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 with resources [] in work directory '/tmp/MasterTest_MasterFailoverLongLivedExecutor_Mpz3TH/slaves/60131ef2-deaa-4674-89cc-679b7615f18d-S0/frameworks/60131ef2-deaa-4674-89cc-679b7615f18d-0000/executors/default/runs/96987039-3c59-4b1a-9e93-acd678f3570f'
3: I1111 06:54:52.518977 18218 slave.cpp:2467] Queued task '1' for executor 'default' of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: I1111 06:54:52.519068 18218 slave.cpp:958] Successfully attached '/tmp/MasterTest_MasterFailoverLongLivedExecutor_Mpz3TH/slaves/60131ef2-deaa-4674-89cc-679b7615f18d-S0/frameworks/60131ef2-deaa-4674-89cc-679b7615f18d-0000/executors/default/runs/96987039-3c59-4b1a-9e93-acd678f3570f' to virtual path '/tmp/MasterTest_MasterFailoverLongLivedExecutor_Mpz3TH/slaves/60131ef2-deaa-4674-89cc-679b7615f18d-S0/frameworks/60131ef2-deaa-4674-89cc-679b7615f18d-0000/executors/default/runs/latest'
3: I1111 06:54:52.519119 18218 slave.cpp:958] Successfully attached '/tmp/MasterTest_MasterFailoverLongLivedExecutor_Mpz3TH/slaves/60131ef2-deaa-4674-89cc-679b7615f18d-S0/frameworks/60131ef2-deaa-4674-89cc-679b7615f18d-0000/executors/default/runs/96987039-3c59-4b1a-9e93-acd678f3570f' to virtual path '/frameworks/60131ef2-deaa-4674-89cc-679b7615f18d-0000/executors/default/runs/latest'
3: I1111 06:54:52.519165 18218 slave.cpp:958] Successfully attached '/tmp/MasterTest_MasterFailoverLongLivedExecutor_Mpz3TH/slaves/60131ef2-deaa-4674-89cc-679b7615f18d-S0/frameworks/60131ef2-deaa-4674-89cc-679b7615f18d-0000/executors/default/runs/96987039-3c59-4b1a-9e93-acd678f3570f' to virtual path '/tmp/MasterTest_MasterFailoverLongLivedExecutor_Mpz3TH/slaves/60131ef2-deaa-4674-89cc-679b7615f18d-S0/frameworks/60131ef2-deaa-4674-89cc-679b7615f18d-0000/executors/default/runs/96987039-3c59-4b1a-9e93-acd678f3570f'
3: I1111 06:54:52.519395 18218 slave.cpp:2930] Launching container 96987039-3c59-4b1a-9e93-acd678f3570f for executor 'default' of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: W1111 06:54:52.521728 18229 process.cpp:3178] Attempted to spawn already running process version@172.17.0.4:33387
3: I1111 06:54:52.521888 18229 exec.cpp:162] Version: 1.5.0
3: I1111 06:54:52.522114 18231 exec.cpp:212] Executor started at: executor(155)@172.17.0.4:33387 with pid 18209
3: I1111 06:54:52.522289 18217 slave.cpp:4053] Got registration for executor 'default' of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 from executor(155)@172.17.0.4:33387
3: I1111 06:54:52.522632 18221 exec.cpp:237] Executor registered on agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0
3: I1111 06:54:52.522675 18221 exec.cpp:249] Executor::registered took 20955ns
3: I1111 06:54:52.522991 18217 slave.cpp:2669] Sending queued task '1' to executor 'default' of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 at executor(155)@172.17.0.4:33387
3: I1111 06:54:52.523278 18225 exec.cpp:331] Executor asked to run task '1'
3: I1111 06:54:52.523363 18225 exec.cpp:340] Executor::launchTask took 65120ns
3: I1111 06:54:52.523463 18225 exec.cpp:571] Executor sending status update TASK_RUNNING (UUID: 592925b2-85b1-4941-86ea-df07c95c861a) for task 1 of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: I1111 06:54:52.523741 18212 slave.cpp:4507] Handling status update TASK_RUNNING (UUID: 592925b2-85b1-4941-86ea-df07c95c861a) for task 1 of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 from executor(155)@172.17.0.4:33387
3: I1111 06:54:52.524505 18219 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: 592925b2-85b1-4941-86ea-df07c95c861a) for task 1 of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: I1111 06:54:52.524544 18219 status_update_manager.cpp:500] Creating StatusUpdate stream for task 1 of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: I1111 06:54:52.524929 18219 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: 592925b2-85b1-4941-86ea-df07c95c861a) for task 1 of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 to the agent
3: I1111 06:54:52.525141 18213 slave.cpp:4988] Forwarding the update TASK_RUNNING (UUID: 592925b2-85b1-4941-86ea-df07c95c861a) for task 1 of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 to master@172.17.0.4:33387
3: I1111 06:54:52.525339 18213 slave.cpp:4882] Status update manager successfully handled status update TASK_RUNNING (UUID: 592925b2-85b1-4941-86ea-df07c95c861a) for task 1 of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: I1111 06:54:52.525384 18213 slave.cpp:4898] Sending acknowledgement for status update TASK_RUNNING (UUID: 592925b2-85b1-4941-86ea-df07c95c861a) for task 1 of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 to executor(155)@172.17.0.4:33387
3: I1111 06:54:52.525501 18215 master.cpp:7248] Status update TASK_RUNNING (UUID: 592925b2-85b1-4941-86ea-df07c95c861a) for task 1 of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 from agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a)
3: I1111 06:54:52.525521 18230 exec.cpp:388] Executor received status update acknowledgement 592925b2-85b1-4941-86ea-df07c95c861a for task 1 of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: I1111 06:54:52.525559 18215 master.cpp:7310] Forwarding status update TASK_RUNNING (UUID: 592925b2-85b1-4941-86ea-df07c95c861a) for task 1 of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: I1111 06:54:52.525801 18215 master.cpp:9503] Updating the state of task 1 of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
3: I1111 06:54:52.526031 18214 sched.cpp:1029] Scheduler::statusUpdate took 93958ns
3: I1111 06:54:52.526335 18216 master.cpp:5792] Processing ACKNOWLEDGE call 592925b2-85b1-4941-86ea-df07c95c861a for task 1 of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 (default) at scheduler-5ab31fb3-f7b1-4382-b0fc-4b36354f41f6@172.17.0.4:33387 on agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0
3: I1111 06:54:52.526487 18216 master.cpp:1151] Master terminating
3: I1111 06:54:52.526630 18233 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 592925b2-85b1-4941-86ea-df07c95c861a) for task 1 of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: W1111 06:54:52.526576 18216 master.cpp:9583] Removing task 1 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 on agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a) in non-removable state TASK_RUNNING
3: I1111 06:54:52.526875 18224 slave.cpp:3791] Status update manager successfully handled status update acknowledgement (UUID: 592925b2-85b1-4941-86ea-df07c95c861a) for task 1 of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: I1111 06:54:52.527344 18229 hierarchical.cpp:626] Removed agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0
3: I1111 06:54:52.527349 18216 master.cpp:9626] Removing executor 'default' with resources [] of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 on agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a)
3: I1111 06:54:52.528246 18230 slave.cpp:5120] Got exited event for master@172.17.0.4:33387
3: W1111 06:54:52.528266 18230 slave.cpp:5125] Master disconnected! Waiting for a new master to be elected
3: I1111 06:54:52.528348 18229 hierarchical.cpp:355] Removed framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: I1111 06:54:52.532456 18209 cluster.cpp:162] Creating default 'local' authorizer
3: I1111 06:54:52.535034 18214 master.cpp:448] Master f54877f4-2991-430c-8d50-5251dd299032 (02e3ced3c06a) started on 172.17.0.4:33387
3: I1111 06:54:52.535051 18214 master.cpp:450] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/Rf5hsy/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/Rf5hsy/master" --zk_session_timeout="10secs"
3: I1111 06:54:52.535338 18214 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1111 06:54:52.535346 18214 master.cpp:505] Master only allowing authenticated agents to register
3: I1111 06:54:52.535351 18214 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1111 06:54:52.535356 18214 credentials.hpp:37] Loading credentials for authentication from '/tmp/Rf5hsy/credentials'
3: I1111 06:54:52.535629 18214 master.cpp:555] Using default 'crammd5' authenticator
3: I1111 06:54:52.535775 18214 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1111 06:54:52.535926 18214 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1111 06:54:52.536056 18214 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1111 06:54:52.536171 18214 master.cpp:634] Authorization enabled
3: I1111 06:54:52.536309 18224 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1111 06:54:52.536334 18217 whitelist_watcher.cpp:77] No whitelist given
3: I1111 06:54:52.538964 18219 master.cpp:2213] Elected as the leading master!
3: I1111 06:54:52.538990 18219 master.cpp:1693] Recovering from registrar
3: I1111 06:54:52.539131 18212 registrar.cpp:347] Recovering registrar
3: I1111 06:54:52.539690 18212 registrar.cpp:391] Successfully fetched the registry (0B) in 519936ns
3: I1111 06:54:52.539786 18212 registrar.cpp:495] Applied 1 operations in 24713ns; attempting to update the registry
3: I1111 06:54:52.540282 18212 registrar.cpp:552] Successfully updated the registry in 442880ns
3: I1111 06:54:52.540388 18212 registrar.cpp:424] Successfully recovered registrar
3: I1111 06:54:52.540737 18222 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1111 06:54:52.540755 18233 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: I1111 06:54:52.541321 18214 status_update_manager.cpp:177] Pausing sending status updates
3: I1111 06:54:52.541329 18229 slave.cpp:1007] New master detected at master@172.17.0.4:33387
3: I1111 06:54:52.541386 18228 sched.cpp:330] Scheduler::disconnected took 16602ns
3: I1111 06:54:52.541404 18228 sched.cpp:336] New master detected at master@172.17.0.4:33387
3: I1111 06:54:52.541409 18229 slave.cpp:1042] Detecting new master
3: I1111 06:54:52.541493 18228 sched.cpp:396] Authenticating with master master@172.17.0.4:33387
3: I1111 06:54:52.541508 18228 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1111 06:54:52.541739 18219 authenticatee.cpp:121] Creating new client SASL connection
3: I1111 06:54:52.541980 18216 master.cpp:8286] Authenticating scheduler-5ab31fb3-f7b1-4382-b0fc-4b36354f41f6@172.17.0.4:33387
3: I1111 06:54:52.542073 18225 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(808)@172.17.0.4:33387
3: I1111 06:54:52.542301 18215 authenticator.cpp:98] Creating new server SASL connection
3: I1111 06:54:52.542616 18227 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1111 06:54:52.542618 18232 slave.cpp:1069] Authenticating with master master@172.17.0.4:33387
3: I1111 06:54:52.542640 18227 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1111 06:54:52.542671 18232 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1111 06:54:52.542752 18223 authenticator.cpp:204] Received SASL authentication start
3: I1111 06:54:52.542810 18223 authenticator.cpp:326] Authentication requires more steps
3: I1111 06:54:52.542856 18220 authenticatee.cpp:121] Creating new client SASL connection
3: I1111 06:54:52.542937 18211 authenticatee.cpp:259] Received SASL authentication step
3: I1111 06:54:52.543035 18220 authenticator.cpp:232] Received SASL authentication step
3: I1111 06:54:52.543061 18220 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '02e3ced3c06a' server FQDN: '02e3ced3c06a' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1111 06:54:52.543071 18220 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1111 06:54:52.543072 18231 master.cpp:8286] Authenticating slave(394)@172.17.0.4:33387
3: I1111 06:54:52.543099 18220 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1111 06:54:52.543118 18220 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '02e3ced3c06a' server FQDN: '02e3ced3c06a' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1111 06:54:52.543124 18220 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1111 06:54:52.543129 18220 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1111 06:54:52.543141 18220 authenticator.cpp:318] Authentication success
3: I1111 06:54:52.543156 18212 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(809)@172.17.0.4:33387
3: I1111 06:54:52.543222 18226 authenticatee.cpp:299] Authentication success
3: I1111 06:54:52.543264 18233 master.cpp:8316] Successfully authenticated principal 'test-principal' at scheduler-5ab31fb3-f7b1-4382-b0fc-4b36354f41f6@172.17.0.4:33387
3: I1111 06:54:52.543380 18221 authenticator.cpp:98] Creating new server SASL connection
3: I1111 06:54:52.543421 18220 sched.cpp:502] Successfully authenticated with master master@172.17.0.4:33387
3: I1111 06:54:52.543437 18220 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.4:33387
3: I1111 06:54:52.543445 18212 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(808)@172.17.0.4:33387
3: I1111 06:54:52.543545 18220 sched.cpp:857] Will retry registration in 1.94743023secs if necessary
3: I1111 06:54:52.543596 18229 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1111 06:54:52.543617 18229 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1111 06:54:52.543717 18210 authenticator.cpp:204] Received SASL authentication start
3: I1111 06:54:52.543725 18213 master.cpp:2962] Received SUBSCRIBE call for framework 'default' at scheduler-5ab31fb3-f7b1-4382-b0fc-4b36354f41f6@172.17.0.4:33387
3: I1111 06:54:52.543769 18210 authenticator.cpp:326] Authentication requires more steps
3: I1111 06:54:52.543812 18213 master.cpp:2278] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
3: I1111 06:54:52.543865 18219 authenticatee.cpp:259] Received SASL authentication step
3: I1111 06:54:52.544001 18225 authenticator.cpp:232] Received SASL authentication step
3: I1111 06:54:52.544031 18225 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '02e3ced3c06a' server FQDN: '02e3ced3c06a' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1111 06:54:52.544045 18225 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1111 06:54:52.544068 18225 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1111 06:54:52.544092 18225 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '02e3ced3c06a' server FQDN: '02e3ced3c06a' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1111 06:54:52.544103 18225 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1111 06:54:52.544108 18225 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1111 06:54:52.544121 18225 authenticator.cpp:318] Authentication success
3: I1111 06:54:52.544195 18215 authenticatee.cpp:299] Authentication success
3: I1111 06:54:52.544252 18227 master.cpp:8316] Successfully authenticated principal 'test-principal' at slave(394)@172.17.0.4:33387
3: I1111 06:54:52.544318 18223 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(809)@172.17.0.4:33387
3: I1111 06:54:52.544349 18227 master.cpp:3042] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1111 06:54:52.544430 18216 slave.cpp:1161] Successfully authenticated with master master@172.17.0.4:33387
3: I1111 06:54:52.544630 18227 master.cpp:6968] Updating info for framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: I1111 06:54:52.544821 18216 slave.cpp:1682] Will retry registration in 13.476707ms if necessary
3: I1111 06:54:52.544915 18222 hierarchical.cpp:303] Added framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: I1111 06:54:52.544958 18222 hierarchical.cpp:412] Deactivated framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: I1111 06:54:52.545001 18230 sched.cpp:751] Framework registered with 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: I1111 06:54:52.545037 18230 sched.cpp:765] Scheduler::registered took 18529ns
3: I1111 06:54:52.545097 18222 hierarchical.cpp:380] Activated framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
3: I1111 06:54:52.545264 18222 hierarchical.cpp:1450] Performed allocation for 0 agents in 65136ns
3: I1111 06:54:52.545450 18227 master.cpp:6351] Received re-register agent message from agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a)
3: I1111 06:54:52.545677 18227 master.cpp:3871] Authorizing agent with principal 'test-principal'
3: I1111 06:54:52.546093 18221 master.cpp:6420] Authorized re-registration of agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a)
3: I1111 06:54:52.546164 18221 master.cpp:6600] Re-registering agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a)
3: W1111 06:54:52.546594 18220 master.hpp:2270] Allowing UNKNOWN agent to reregister: hostname: "02e3ced3c06a"
3: resources {
3: name: "cpus"
3: type: SCALAR
3: scalar {
3: value: 2
3: }
3: role: "*"
3: }
3: resources {
3: name: "mem"
3: type: SCALAR
3: scalar {
3: value: 1024
3: }
3: role: "*"
3: }
3: resources {
3: name: "disk"
3: type: SCALAR
3: scalar {
3: value: 367489
3: }
3: role: "*"
3: }
3: resources {
3: name: "ports"
3: type: RANGES
3: ranges {
3: range {
3: begin: 31000
3: end: 32000
3: }
3: }
3: role: "*"
3: }
3: id {
3: value: "60131ef2-deaa-4674-89cc-679b7615f18d-S0"
3: }
3: checkpoint: true
3: port: 33387
3: I1111 06:54:52.546847 18220 registrar.cpp:495] Applied 1 operations in 272993ns; attempting to update the registry
3: I1111 06:54:52.547511 18220 registrar.cpp:552] Successfully updated the registry in 596992ns
3: I1111 06:54:52.547927 18219 master.cpp:6669] Re-admitted agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a)
3: I1111 06:54:52.548368 18219 master.cpp:10762] Adding task 1 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] on agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a)
3: I1111 06:54:52.549119 18211 slave.cpp:1340] Re-registered with master master@172.17.0.4:33387
3: I1111 06:54:52.549192 18225 status_update_manager.cpp:184] Resuming sending status updates
3: I1111 06:54:52.549224 18211 slave.cpp:1397] Forwarding total oversubscribed resources {}
3: I1111 06:54:52.549036 18219 master.cpp:6847] Re-registered agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a) with [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":367489.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1111 06:54:52.549456 18231 slave.cpp:3438] Updating info for framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 with pid updated to scheduler-5ab31fb3-f7b1-4382-b0fc-4b36354f41f6@172.17.0.4:33387
3: I1111 06:54:52.549500 18219 master.cpp:7065] Received update of agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a) with total oversubscribed resources {}
3: I1111 06:54:52.549546 18231 status_update_manager.cpp:184] Resuming sending status updates
3: I1111 06:54:52.549646 18219 master.cpp:7083] Ignoring update on agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a) as it reports no changes
3: I1111 06:54:52.549650 18218 hierarchical.cpp:593] Added agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 (02e3ced3c06a) with cpus:2; mem:1024; disk:367489; ports:[31000-32000] (allocated: cpus(allocated: *):1; mem(allocated: *):512)
3: I1111 06:54:52.550763 18218 hierarchical.cpp:1450] Performed allocation for 1 agents in 959777ns
3: I1111 06:54:52.551259 18223 master.cpp:8116] Sending 1 offers to framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 (default) at scheduler-5ab31fb3-f7b1-4382-b0fc-4b36354f41f6@172.17.0.4:33387
3: I1111 06:54:52.551738 18233 sched.cpp:921] Scheduler::resourceOffers took 103107ns
3: I1111 06:54:52.553735 18221 master.cpp:10016] Removing offer f54877f4-2991-430c-8d50-5251dd299032-O0
3: I1111 06:54:52.553961 18221 master.cpp:4229] Processing ACCEPT call for offers: [ f54877f4-2991-430c-8d50-5251dd299032-O0 ] on agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a) for framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 (default) at scheduler-5ab31fb3-f7b1-4382-b0fc-4b36354f41f6@172.17.0.4:33387
3: I1111 06:54:52.554082 18221 master.cpp:3598] Authorizing framework principal 'test-principal' to launch task 2
3: W1111 06:54:52.556732 18221 validation.cpp:1404] Executor 'default' for task '2' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
3: W1111 06:54:52.556783 18221 validation.cpp:1416] Executor 'default' for task '2' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
3: I1111 06:54:52.557270 18221 master.cpp:10762] Adding task 2 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] on agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a)
3: I1111 06:54:52.557801 18221 master.cpp:4977] Launching task 2 of framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000 (default) at scheduler-5ab31fb3-f7b1-4382-b0fc-4b36354f41f6@172.17.0.4:33387 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] on agent 60131ef2-deaa-4674-89cc-679b7615f18d-S0 at slave(394)@172.17.0.4:33387 (02e3ced3c06a)
3: I1111 06:54:52.558495 18220 slave.cpp:1803] Got assigned task '2' for framework 60131ef2-deaa-4674-89cc-679b7615f18d-0000
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1510381226-4810
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user yujie.jay@gmail.com
Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,centos:7,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4444
Posted by 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%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4444/display/redirect?page=changes>
Changes:
[jpeach] Made Envp conversion operator consistent with Argv.
[jpeach] Deleted Argv copy constructor and assignment members.
------------------------------------------
[...truncated 13.95 MB...]
3: I1111 01:54:25.978786 17487 slave.cpp:5120] Got exited event for executor(114)@172.17.0.3:60743
3: I1111 01:54:25.978994 17484 hierarchical.cpp:1125] Recovered cpus(allocated: *):1; mem(allocated: *):500 (total: cpus:2; mem:1024; disk:3701220; ports:[31000-32000], allocated: {}) on agent 413c36ed-7e53-434f-822b-de3fd748abce-S0 from framework 413c36ed-7e53-434f-822b-de3fd748abce-0000
3: I1111 01:54:25.978862 17493 master.cpp:9597] Removing task 0 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":500.0},"type":"SCALAR"}] of framework 413c36ed-7e53-434f-822b-de3fd748abce-0000 on agent 413c36ed-7e53-434f-822b-de3fd748abce-S0 at slave(292)@172.17.0.3:60743 (31255769382b)
3: I1111 01:54:25.979301 17493 master.cpp:9626] Removing executor 'default' with resources [] of framework 413c36ed-7e53-434f-822b-de3fd748abce-0000 on agent 413c36ed-7e53-434f-822b-de3fd748abce-S0 at slave(292)@172.17.0.3:60743 (31255769382b)
3: I1111 01:54:25.979925 17493 master.cpp:1151] Master terminating
3: I1111 01:54:25.980172 17486 hierarchical.cpp:355] Removed framework 413c36ed-7e53-434f-822b-de3fd748abce-0000
3: I1111 01:54:25.980628 17493 slave.cpp:5120] Got exited event for master@172.17.0.3:60743
3: W1111 01:54:25.980651 17493 slave.cpp:5125] Master disconnected! Waiting for a new master to be elected
3: I1111 01:54:25.980859 17486 hierarchical.cpp:626] Removed agent 413c36ed-7e53-434f-822b-de3fd748abce-S0
3: I1111 01:54:25.985066 17495 slave.cpp:5520] Executor 'default' of framework 413c36ed-7e53-434f-822b-de3fd748abce-0000 exited with status 0
3: I1111 01:54:25.985285 17495 slave.cpp:5624] Cleaning up executor 'default' of framework 413c36ed-7e53-434f-822b-de3fd748abce-0000 at executor(114)@172.17.0.3:60743
3: I1111 01:54:25.985579 17486 gc.cpp:90] Scheduling '/tmp/MasterAllocatorTest_1_FrameworkReregistersFirst_7TyMrV/slaves/413c36ed-7e53-434f-822b-de3fd748abce-S0/frameworks/413c36ed-7e53-434f-822b-de3fd748abce-0000/executors/default/runs/3babe59c-8ea7-4e37-891f-23faac9c9e9d' for gc 6.99998859429333days in the future
3: I1111 01:54:25.985709 17495 slave.cpp:5731] Cleaning up framework 413c36ed-7e53-434f-822b-de3fd748abce-0000
3: I1111 01:54:25.985756 17486 gc.cpp:90] Scheduling '/tmp/MasterAllocatorTest_1_FrameworkReregistersFirst_7TyMrV/slaves/413c36ed-7e53-434f-822b-de3fd748abce-S0/frameworks/413c36ed-7e53-434f-822b-de3fd748abce-0000/executors/default' for gc 6.99998859215407days in the future
3: I1111 01:54:25.985882 17488 status_update_manager.cpp:285] Closing status update streams for framework 413c36ed-7e53-434f-822b-de3fd748abce-0000
3: I1111 01:54:25.985944 17488 status_update_manager.cpp:531] Cleaning up status update stream for task 0 of framework 413c36ed-7e53-434f-822b-de3fd748abce-0000
3: I1111 01:54:25.986086 17486 gc.cpp:90] Scheduling '/tmp/MasterAllocatorTest_1_FrameworkReregistersFirst_7TyMrV/slaves/413c36ed-7e53-434f-822b-de3fd748abce-S0/frameworks/413c36ed-7e53-434f-822b-de3fd748abce-0000' for gc 6.99998858949037days in the future
3: I1111 01:54:25.986114 17494 slave.cpp:883] Agent terminating
3: [ OK ] MasterAllocatorTest/1.FrameworkReregistersFirst (127 ms)
3: [ RUN ] MasterAllocatorTest/1.SlaveReregistersFirst
3: W1111 01:54:25.992926 17482 process.cpp:3178] Attempted to spawn already running process version@172.17.0.3:60743
3: I1111 01:54:25.995831 17482 cluster.cpp:162] Creating default 'local' authorizer
3: I1111 01:54:25.998656 17490 master.cpp:448] Master 604719d2-da2d-4af4-a764-0667a6967181 (31255769382b) started on 172.17.0.3:60743
3: I1111 01:54:25.998679 17490 master.cpp:450] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/Z6QAP9/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/Z6QAP9/master" --zk_session_timeout="10secs"
3: I1111 01:54:25.998963 17490 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1111 01:54:25.998972 17490 master.cpp:505] Master only allowing authenticated agents to register
3: I1111 01:54:25.998977 17490 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1111 01:54:25.998983 17490 credentials.hpp:37] Loading credentials for authentication from '/tmp/Z6QAP9/credentials'
3: I1111 01:54:25.999276 17490 master.cpp:555] Using default 'crammd5' authenticator
3: I1111 01:54:25.999428 17490 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1111 01:54:25.999593 17490 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1111 01:54:25.999734 17490 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1111 01:54:25.999837 17490 master.cpp:634] Authorization enabled
3: I1111 01:54:26.000099 17495 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1111 01:54:26.000102 17494 whitelist_watcher.cpp:77] No whitelist given
3: I1111 01:54:26.003001 17497 master.cpp:2213] Elected as the leading master!
3: I1111 01:54:26.003029 17497 master.cpp:1693] Recovering from registrar
3: I1111 01:54:26.003160 17488 registrar.cpp:347] Recovering registrar
3: I1111 01:54:26.003736 17488 registrar.cpp:391] Successfully fetched the registry (0B) in 536832ns
3: I1111 01:54:26.003862 17488 registrar.cpp:495] Applied 1 operations in 41551ns; attempting to update the registry
3: I1111 01:54:26.004500 17488 registrar.cpp:552] Successfully updated the registry in 550912ns
3: I1111 01:54:26.004644 17488 registrar.cpp:424] Successfully recovered registrar
3: I1111 01:54:26.005167 17494 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1111 01:54:26.005201 17493 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: W1111 01:54:26.010690 17482 process.cpp:3178] Attempted to spawn already running process files@172.17.0.3:60743
3: I1111 01:54:26.011070 17482 cluster.cpp:448] Creating default 'local' authorizer
3: I1111 01:54:26.013631 17490 slave.cpp:262] Mesos agent started on (293)@172.17.0.3:60743
3: I1111 01:54:26.013654 17490 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_kuOMuM/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/MasterAllocatorTest_1_SlaveReregistersFirst_kuOMuM/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/MasterAllocatorTest_1_SlaveReregistersFirst_kuOMuM/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_secret_key="/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_kuOMuM/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_kuOMuM/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/MasterAllocatorTest_1_SlaveReregistersFirst_kuOMuM/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;mem:1024" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_kuOMuM" --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/MasterAllocatorTest_1_SlaveReregistersFirst_qlebaY" --zk_session_timeout="10secs"
3: I1111 01:54:26.014102 17490 credentials.hpp:86] Loading credential for authentication from '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_kuOMuM/credential'
3: I1111 01:54:26.014272 17490 slave.cpp:295] Agent using credential for: test-principal
3: I1111 01:54:26.014293 17490 credentials.hpp:37] Loading credentials for authentication from '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_kuOMuM/http_credentials'
3: I1111 01:54:26.014632 17490 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1111 01:54:26.014765 17490 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1111 01:54:26.014989 17482 sched.cpp:232] Version: 1.5.0
3: I1111 01:54:26.015048 17490 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1111 01:54:26.015177 17490 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1111 01:54:26.015565 17490 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1111 01:54:26.015669 17495 sched.cpp:336] New master detected at master@172.17.0.3:60743
3: I1111 01:54:26.015689 17490 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1111 01:54:26.015808 17495 sched.cpp:396] Authenticating with master master@172.17.0.3:60743
3: I1111 01:54:26.015828 17495 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1111 01:54:26.016152 17497 authenticatee.cpp:121] Creating new client SASL connection
3: I1111 01:54:26.016429 17489 master.cpp:8286] Authenticating scheduler-954db9c3-1179-44cc-baea-82c397f11af7@172.17.0.3:60743
3: I1111 01:54:26.016532 17498 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(613)@172.17.0.3:60743
3: I1111 01:54:26.016803 17491 authenticator.cpp:98] Creating new server SASL connection
3: I1111 01:54:26.017045 17494 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1111 01:54:26.017071 17494 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1111 01:54:26.017298 17488 authenticator.cpp:204] Received SASL authentication start
3: I1111 01:54:26.017393 17488 authenticator.cpp:326] Authentication requires more steps
3: I1111 01:54:26.017530 17483 authenticatee.cpp:259] Received SASL authentication step
3: I1111 01:54:26.017297 17490 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":3701220.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1111 01:54:26.017594 17490 slave.cpp:601] Agent attributes: [ ]
3: I1111 01:54:26.017608 17490 slave.cpp:610] Agent hostname: 31255769382b
3: I1111 01:54:26.017676 17496 authenticator.cpp:232] Received SASL authentication step
3: I1111 01:54:26.017712 17496 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '31255769382b' server FQDN: '31255769382b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1111 01:54:26.017731 17496 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1111 01:54:26.017755 17493 status_update_manager.cpp:177] Pausing sending status updates
3: I1111 01:54:26.017782 17496 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1111 01:54:26.017813 17496 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '31255769382b' server FQDN: '31255769382b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1111 01:54:26.017827 17496 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1111 01:54:26.017837 17496 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1111 01:54:26.017854 17496 authenticator.cpp:318] Authentication success
3: I1111 01:54:26.017971 17484 authenticatee.cpp:299] Authentication success
3: I1111 01:54:26.018077 17487 master.cpp:8316] Successfully authenticated principal 'test-principal' at scheduler-954db9c3-1179-44cc-baea-82c397f11af7@172.17.0.3:60743
3: I1111 01:54:26.018120 17495 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(613)@172.17.0.3:60743
3: I1111 01:54:26.018307 17496 sched.cpp:502] Successfully authenticated with master master@172.17.0.3:60743
3: I1111 01:54:26.018327 17496 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.3:60743
3: I1111 01:54:26.018471 17496 sched.cpp:857] Will retry registration in 754.340772ms if necessary
3: I1111 01:54:26.018666 17498 master.cpp:2962] Received SUBSCRIBE call for framework 'default' at scheduler-954db9c3-1179-44cc-baea-82c397f11af7@172.17.0.3:60743
3: I1111 01:54:26.018741 17498 master.cpp:2278] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
3: I1111 01:54:26.019290 17483 master.cpp:3042] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1111 01:54:26.019680 17484 state.cpp:64] Recovering state from '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_qlebaY/meta'
3: I1111 01:54:26.020081 17495 status_update_manager.cpp:203] Recovering status update manager
3: I1111 01:54:26.020131 17483 sched.cpp:751] Framework registered with 604719d2-da2d-4af4-a764-0667a6967181-0000
3: I1111 01:54:26.020156 17490 hierarchical.cpp:303] Added framework 604719d2-da2d-4af4-a764-0667a6967181-0000
3: I1111 01:54:26.020170 17483 sched.cpp:765] Scheduler::registered took 21128ns
3: I1111 01:54:26.020412 17490 hierarchical.cpp:1450] Performed allocation for 0 agents in 91241ns
3: I1111 01:54:26.020540 17491 slave.cpp:6422] Finished recovery
3: I1111 01:54:26.021378 17493 slave.cpp:1007] New master detected at master@172.17.0.3:60743
3: I1111 01:54:26.021399 17485 status_update_manager.cpp:177] Pausing sending status updates
3: I1111 01:54:26.021464 17493 slave.cpp:1042] Detecting new master
3: I1111 01:54:26.029824 17484 slave.cpp:1069] Authenticating with master master@172.17.0.3:60743
3: I1111 01:54:26.029878 17484 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1111 01:54:26.030087 17492 authenticatee.cpp:121] Creating new client SASL connection
3: I1111 01:54:26.030364 17486 master.cpp:8286] Authenticating slave(293)@172.17.0.3:60743
3: I1111 01:54:26.030499 17487 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(614)@172.17.0.3:60743
3: I1111 01:54:26.030748 17496 authenticator.cpp:98] Creating new server SASL connection
3: I1111 01:54:26.030969 17483 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1111 01:54:26.031000 17483 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1111 01:54:26.031147 17495 authenticator.cpp:204] Received SASL authentication start
3: I1111 01:54:26.031213 17495 authenticator.cpp:326] Authentication requires more steps
3: I1111 01:54:26.031352 17489 authenticatee.cpp:259] Received SASL authentication step
3: I1111 01:54:26.031491 17498 authenticator.cpp:232] Received SASL authentication step
3: I1111 01:54:26.031525 17498 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '31255769382b' server FQDN: '31255769382b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1111 01:54:26.031539 17498 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1111 01:54:26.031591 17498 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1111 01:54:26.031623 17498 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '31255769382b' server FQDN: '31255769382b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1111 01:54:26.031646 17498 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1111 01:54:26.031654 17498 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1111 01:54:26.031672 17498 authenticator.cpp:318] Authentication success
3: I1111 01:54:26.031747 17490 authenticatee.cpp:299] Authentication success
3: I1111 01:54:26.031806 17491 master.cpp:8316] Successfully authenticated principal 'test-principal' at slave(293)@172.17.0.3:60743
3: I1111 01:54:26.031843 17494 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(614)@172.17.0.3:60743
3: I1111 01:54:26.032065 17498 slave.cpp:1161] Successfully authenticated with master master@172.17.0.3:60743
3: I1111 01:54:26.032325 17498 slave.cpp:1682] Will retry registration in 19.125689ms if necessary
3: I1111 01:54:26.032596 17486 master.cpp:6033] Received register agent message from slave(293)@172.17.0.3:60743 (31255769382b)
3: I1111 01:54:26.032755 17486 master.cpp:3871] Authorizing agent with principal 'test-principal'
3: I1111 01:54:26.033182 17496 master.cpp:6093] Authorized registration of agent at slave(293)@172.17.0.3:60743 (31255769382b)
3: I1111 01:54:26.033310 17496 master.cpp:6186] Registering agent at slave(293)@172.17.0.3:60743 (31255769382b) with id 604719d2-da2d-4af4-a764-0667a6967181-S0
3: I1111 01:54:26.033780 17483 registrar.cpp:495] Applied 1 operations in 60771ns; attempting to update the registry
3: I1111 01:54:26.034399 17483 registrar.cpp:552] Successfully updated the registry in 556800ns
3: I1111 01:54:26.034636 17490 master.cpp:6233] Admitted agent 604719d2-da2d-4af4-a764-0667a6967181-S0 at slave(293)@172.17.0.3:60743 (31255769382b)
3: I1111 01:54:26.035483 17485 slave.cpp:1207] Registered with master master@172.17.0.3:60743; given agent ID 604719d2-da2d-4af4-a764-0667a6967181-S0
3: I1111 01:54:26.035614 17494 status_update_manager.cpp:184] Resuming sending status updates
3: I1111 01:54:26.035372 17490 master.cpp:6264] Registered agent 604719d2-da2d-4af4-a764-0667a6967181-S0 at slave(293)@172.17.0.3:60743 (31255769382b) with [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":3701220.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1111 01:54:26.035948 17485 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_qlebaY/meta/slaves/604719d2-da2d-4af4-a764-0667a6967181-S0/slave.info'
3: I1111 01:54:26.036113 17497 hierarchical.cpp:593] Added agent 604719d2-da2d-4af4-a764-0667a6967181-S0 (31255769382b) with cpus:2; mem:1024; disk:3701220; ports:[31000-32000] (allocated: {})
3: I1111 01:54:26.036535 17485 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: I1111 01:54:26.036752 17492 master.cpp:7065] Received update of agent 604719d2-da2d-4af4-a764-0667a6967181-S0 at slave(293)@172.17.0.3:60743 (31255769382b) with total oversubscribed resources {}
3: I1111 01:54:26.036939 17492 master.cpp:7083] Ignoring update on agent 604719d2-da2d-4af4-a764-0667a6967181-S0 at slave(293)@172.17.0.3:60743 (31255769382b) as it reports no changes
3: I1111 01:54:26.037703 17497 hierarchical.cpp:1450] Performed allocation for 1 agents in 1.347399ms
3: I1111 01:54:26.038291 17498 master.cpp:8116] Sending 1 offers to framework 604719d2-da2d-4af4-a764-0667a6967181-0000 (default) at scheduler-954db9c3-1179-44cc-baea-82c397f11af7@172.17.0.3:60743
3: I1111 01:54:26.039698 17498 sched.cpp:921] Scheduler::resourceOffers took 922449ns
3: I1111 01:54:26.041193 17487 master.cpp:10016] Removing offer 604719d2-da2d-4af4-a764-0667a6967181-O0
3: I1111 01:54:26.041357 17487 master.cpp:4229] Processing ACCEPT call for offers: [ 604719d2-da2d-4af4-a764-0667a6967181-O0 ] on agent 604719d2-da2d-4af4-a764-0667a6967181-S0 at slave(293)@172.17.0.3:60743 (31255769382b) for framework 604719d2-da2d-4af4-a764-0667a6967181-0000 (default) at scheduler-954db9c3-1179-44cc-baea-82c397f11af7@172.17.0.3:60743
3: I1111 01:54:26.041457 17487 master.cpp:3598] Authorizing framework principal 'test-principal' to launch task 0
3: W1111 01:54:26.043673 17495 validation.cpp:1404] Executor 'default' for task '0' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
3: W1111 01:54:26.043712 17495 validation.cpp:1416] Executor 'default' for task '0' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
3: I1111 01:54:26.044273 17495 master.cpp:10762] Adding task 0 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":500.0},"type":"SCALAR"}] on agent 604719d2-da2d-4af4-a764-0667a6967181-S0 at slave(293)@172.17.0.3:60743 (31255769382b)
3: I1111 01:54:26.044714 17495 master.cpp:4977] Launching task 0 of framework 604719d2-da2d-4af4-a764-0667a6967181-0000 (default) at scheduler-954db9c3-1179-44cc-baea-82c397f11af7@172.17.0.3:60743 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":500.0},"type":"SCALAR"}] on agent 604719d2-da2d-4af4-a764-0667a6967181-S0 at slave(293)@172.17.0.3:60743 (31255769382b)
3: I1111 01:54:26.045397 17491 slave.cpp:1803] Got assigned task '0' for framework 604719d2-da2d-4af4-a764-0667a6967181-0000
3: I1111 01:54:26.046124 17491 slave.cpp:2071] Authorizing task '0' for framework 604719d2-da2d-4af4-a764-0667a6967181-0000
3: I1111 01:54:26.046186 17491 slave.cpp:7030] Authorizing framework principal 'test-principal' to launch task 0
3: I1111 01:54:26.046205 17483 hierarchical.cpp:1125] Recovered cpus(allocated: *):1; mem(allocated: *):524; disk(allocated: *):3701220; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:3701220; ports:[31000-32000], allocated: cpus(allocated: *):1; mem(allocated: *):500) on agent 604719d2-da2d-4af4-a764-0667a6967181-S0 from framework 604719d2-da2d-4af4-a764-0667a6967181-0000
3: I1111 01:54:26.046299 17483 hierarchical.cpp:1171] Framework 604719d2-da2d-4af4-a764-0667a6967181-0000 filtered agent 604719d2-da2d-4af4-a764-0667a6967181-S0 for 5secs
3: I1111 01:54:26.047102 17490 slave.cpp:2239] Launching task '0' for framework 604719d2-da2d-4af4-a764-0667a6967181-0000
3: I1111 01:54:26.047776 17490 paths.cpp:605] Trying to chown '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_qlebaY/slaves/604719d2-da2d-4af4-a764-0667a6967181-S0/frameworks/604719d2-da2d-4af4-a764-0667a6967181-0000/executors/default/runs/7a858a22-2cc0-4774-a7a8-46c86fff4800' to user 'mesos'
3: I1111 01:54:26.048053 17490 slave.cpp:7504] Launching executor 'default' of framework 604719d2-da2d-4af4-a764-0667a6967181-0000 with resources [] in work directory '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_qlebaY/slaves/604719d2-da2d-4af4-a764-0667a6967181-S0/frameworks/604719d2-da2d-4af4-a764-0667a6967181-0000/executors/default/runs/7a858a22-2cc0-4774-a7a8-46c86fff4800'
3: I1111 01:54:26.049296 17490 slave.cpp:2467] Queued task '0' for executor 'default' of framework 604719d2-da2d-4af4-a764-0667a6967181-0000
3: I1111 01:54:26.049391 17490 slave.cpp:958] Successfully attached '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_qlebaY/slaves/604719d2-da2d-4af4-a764-0667a6967181-S0/frameworks/604719d2-da2d-4af4-a764-0667a6967181-0000/executors/default/runs/7a858a22-2cc0-4774-a7a8-46c86fff4800' to virtual path '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_qlebaY/slaves/604719d2-da2d-4af4-a764-0667a6967181-S0/frameworks/604719d2-da2d-4af4-a764-0667a6967181-0000/executors/default/runs/latest'
3: I1111 01:54:26.049441 17490 slave.cpp:958] Successfully attached '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_qlebaY/slaves/604719d2-da2d-4af4-a764-0667a6967181-S0/frameworks/604719d2-da2d-4af4-a764-0667a6967181-0000/executors/default/runs/7a858a22-2cc0-4774-a7a8-46c86fff4800' to virtual path '/frameworks/604719d2-da2d-4af4-a764-0667a6967181-0000/executors/default/runs/latest'
3: I1111 01:54:26.049484 17490 slave.cpp:958] Successfully attached '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_qlebaY/slaves/604719d2-da2d-4af4-a764-0667a6967181-S0/frameworks/604719d2-da2d-4af4-a764-0667a6967181-0000/executors/default/runs/7a858a22-2cc0-4774-a7a8-46c86fff4800' to virtual path '/tmp/MasterAllocatorTest_1_SlaveReregistersFirst_qlebaY/slaves/604719d2-da2d-4af4-a764-0667a6967181-S0/frameworks/604719d2-da2d-4af4-a764-0667a6967181-0000/executors/default/runs/7a858a22-2cc0-4774-a7a8-46c86fff4800'
3: I1111 01:54:26.049752 17490 slave.cpp:2930] Launching container 7a858a22-2cc0-4774-a7a8-46c86fff4800 for executor 'default' of framework 604719d2-da2d-4af4-a764-0667a6967181-0000
3: W1111 01:54:26.052723 17497 process.cpp:3178] Attempted to spawn already running process version@172.17.0.3:60743
3: I1111 01:54:26.052918 17497 exec.cpp:162] Version: 1.5.0
3: I1111 01:54:26.053186 17498 exec.cpp:212] Executor started at: executor(115)@172.17.0.3:60743 with pid 17482
3: I1111 01:54:26.053407 17498 slave.cpp:4053] Got registration for executor 'default' of framework 604719d2-da2d-4af4-a764-0667a6967181-0000 from executor(115)@172.17.0.3:60743
3: I1111 01:54:26.053850 17487 exec.cpp:237] Executor registered on agent 604719d2-da2d-4af4-a764-0667a6967181-S0
3: I1111 01:54:26.053900 17487 exec.cpp:249] Executor::registered took 24662ns
3: I1111 01:54:26.054374 17498 slave.cpp:2669] Sending queued task '0' to executor 'default' of framework 604719d2-da2d-4af4-a764-0667a6967181-0000 at executor(115)@172.17.0.3:60743
3: I1111 01:54:26.054816 17495 exec.cpp:331] Executor asked to run task '0'
3: I1111 01:54:26.054910 17495 exec.cpp:340] Executor::launchTask took 69921ns
3: I1111 01:54:26.055019 17495 exec.cpp:571] Executor sending status update TASK_RUNNING (UUID: f99de781-2752-42c3-94da-36c550c180d7) for task 0 of framework 604719d2-da2d-4af4-a764-0667a6967181-0000
3: I1111 01:54:26.055328 17495 slave.cpp:4507] Handling status update TASK_RUNNING (UUID: f99de781-2752-42c3-94da-36c550c180d7) for task 0 of framework 604719d2-da2d-4af4-a764-0667a6967181-0000 from executor(115)@172.17.0.3:60743
3: I1111 01:54:26.056077 17493 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: f99de781-2752-42c3-94da-36c550c180d7) for task 0 of framework 604719d2-da2d-4af4-a764-0667a6967181-0000
3: I1111 01:54:26.056136 17493 status_update_manager.cpp:500] Creating StatusUpdate stream for task 0 of framework 604719d2-da2d-4af4-a764-0667a6967181-0000
3: I1111 01:54:26.056591 17493 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: f99de781-2752-42c3-94da-36c550c180d7) for task 0 of framework 604719d2-da2d-4af4-a764-0667a6967181-0000 to the agent
3: I1111 01:54:26.056854 17494 slave.cpp:4988] Forwarding the update TASK_RUNNING (UUID: f99de781-2752-42c3-94da-36c550c180d7) for task 0 of framework 604719d2-da2d-4af4-a764-0667a6967181-0000 to master@172.17.0.3:60743
3: I1111 01:54:26.057095 17494 slave.cpp:4882] Status update manager successfully handled status update TASK_RUNNING (UUID: f99de781-2752-42c3-94da-36c550c180d7) for task 0 of framework 604719d2-da2d-4af4-a764-0667a6967181-0000
3: I1111 01:54:26.057150 17494 slave.cpp:4898] Sending acknowledgement for status update TASK_RUNNING (UUID: f99de781-2752-42c3-94da-36c550c180d7) for task 0 of framework 604719d2-da2d-4af4-a764-0667a6967181-0000 to executor(115)@172.17.0.3:60743
3: I1111 01:54:26.057338 17492 exec.cpp:388] Executor received status update acknowledgement f99de781-2752-42c3-94da-36c550c180d7 for task 0 of framework 604719d2-da2d-4af4-a764-0667a6967181-0000
3: I1111 01:54:26.057344 17485 master.cpp:7248] Status update TASK_RUNNING (UUID: f99de781-2752-42c3-94da-36c550c180d7) for task 0 of framework 604719d2-da2d-4af4-a764-0667a6967181-0000 from agent 604719d2-da2d-4af4-a764-0667a6967181-S0 at slave(293)@172.17.0.3:60743 (31255769382b)
3: I1111 01:54:26.057430 17485 master.cpp:7310] Forwarding status update TASK_RUNNING (UUID: f99de781-2752-42c3-94da-36c550c180d7) for task 0 of framework 604719d2-da2d-4af4-a764-0667a6967181-0000
3: I1111 01:54:26.057656 17485 master.cpp:9503] Updating the state of task 0 of framework 604719d2-da2d-4af4-a764-0667a6967181-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
3: I1111 01:54:26.057924 17490 sched.cpp:1029] Scheduler::statusUpdate took 110093ns
3: I1111 01:54:26.058382 17487 master.cpp:5792] Processing ACKNOWLEDGE call f99de781-2752-42c3-94da-36c550c180d7 for task 0 of framework 604719d2-da2d-4af4-a764-0667a6967181-0000 (default) at scheduler-954db9c3-1179-44cc-baea-82c397f11af7@172.17.0.3:60743 on agent 604719d2-da2d-4af4-a764-0667a6967181-S0
3: I1111 01:54:26.058751 17495 status_update_manager.cpp:395] Received status update acknowledgement (UUID: f99de781-2752-42c3-94da-36c550c180d7) for task 0 of framework 604719d2-da2d-4af4-a764-0667a6967181-0000
3: I1111 01:54:26.059101 17491 slave.cpp:3791] Status update manager successfully handled status update acknowledgement (UUID: f99de781-2752-42c3-94da-36c550c180d7) for task 0 of framework 604719d2-da2d-4af4-a764-0667a6967181-0000
3: I1111 01:54:26.059751 17482 master.cpp:1151] Master terminating
3: W1111 01:54:26.059936 17482 master.cpp:9583] Removing task 0 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":500.0},"type":"SCALAR"}] of framework 604719d2-da2d-4af4-a764-0667a6967181-0000 on agent 604719d2-da2d-4af4-a764-0667a6967181-S0 at slave(293)@172.17.0.3:60743 (31255769382b) in non-removable state TASK_RUNNING
3: I1111 01:54:26.060513 17489 hierarchical.cpp:626] Removed agent 604719d2-da2d-4af4-a764-0667a6967181-S0
3: I1111 01:54:26.060674 17482 master.cpp:9626] Removing executor 'default' with resources [] of framework 604719d2-da2d-4af4-a764-0667a6967181-0000 on agent 604719d2-da2d-4af4-a764-0667a6967181-S0 at slave(293)@172.17.0.3:60743 (31255769382b)
3: I1111 01:54:26.061512 17483 hierarchical.cpp:355] Removed framework 604719d2-da2d-4af4-a764-0667a6967181-0000
3: I1111 01:54:26.061772 17496 slave.cpp:5120] Got exited event for master@172.17.0.3:60743
3: W1111 01:54:26.061805 17496 slave.cpp:5125] Master disconnected! Waiting for a new master to be elected
3: I1111 01:54:26.071571 17482 cluster.cpp:162] Creating default 'local' authorizer
3: I1111 01:54:26.074749 17494 master.cpp:448] Master 5756b31c-ec74-4dfc-9c9c-d2e43823f85d (31255769382b) started on 172.17.0.3:60743
3: I1111 01:54:26.074779 17494 master.cpp:450] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/Z6QAP9/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/Z6QAP9/master" --zk_session_timeout="10secs"
3: I1111 01:54:26.075124 17494 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1111 01:54:26.075139 17494 master.cpp:505] Master only allowing authenticated agents to register
3: I1111 01:54:26.075150 17494 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1111 01:54:26.075161 17494 credentials.hpp:37] Loading credentials for authentication from '/tmp/Z6QAP9/credentials'
3: I1111 01:54:26.075500 17494 master.cpp:555] Using default 'crammd5' authenticator
3: I1111 01:54:26.075677 17494 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1111 01:54:26.075867 17494 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1111 01:54:26.076067 17494 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1111 01:54:26.076238 17494 master.cpp:634] Authorization enabled
3: I1111 01:54:26.076483 17487 whitelist_watcher.cpp:77] No whitelist given
3: I1111 01:54:26.076531 17498 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1111 01:54:26.079617 17495 master.cpp:2213] Elected as the leading master!
3: I1111 01:54:26.079649 17495 master.cpp:1693] Recovering from registrar
3: I1111 01:54:26.079818 17483 registrar.cpp:347] Recovering registrar
3: I1111 01:54:26.080476 17483 registrar.cpp:391] Successfully fetched the registry (0B) in 612864ns
3: I1111 01:54:26.080590 17483 registrar.cpp:495] Applied 1 operations in 31969ns; attempting to update the registry
3: I1111 01:54:26.081254 17483 registrar.cpp:552] Successfully updated the registry in 598016ns
3: I1111 01:54:26.081401 17483 registrar.cpp:424] Successfully recovered registrar
3: I1111 01:54:26.081885 17487 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1111 01:54:26.081903 17492 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: I1111 01:54:26.082653 17493 slave.cpp:1007] New master detected at master@172.17.0.3:60743
3: I1111 01:54:26.082672 17484 status_update_manager.cpp:177] Pausing sending status updates
3: I1111 01:54:26.082737 17493 slave.cpp:1042] Detecting new master
3: I1111 01:54:26.091027 17486 slave.cpp:1069] Authenticating with master master@172.17.0.3:60743
3: I1111 01:54:26.091099 17486 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1111 01:54:26.091367 17485 authenticatee.cpp:121] Creating new client SASL connection
3: I1111 01:54:26.091740 17497 master.cpp:8286] Authenticating slave(293)@172.17.0.3:60743
3: I1111 01:54:26.091861 17483 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(615)@172.17.0.3:60743
3: I1111 01:54:26.092270 17498 authenticator.cpp:98] Creating new server SASL connection
3: I1111 01:54:26.092535 17494 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1111 01:54:26.092563 17494 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1111 01:54:26.092674 17487 authenticator.cpp:204] Received SASL authentication start
3: I1111 01:54:26.092732 17487 authenticator.cpp:326] Authentication requires more steps
3: I1111 01:54:26.092835 17492 authenticatee.cpp:259] Received SASL authentication step
3: I1111 01:54:26.092954 17489 authenticator.cpp:232] Received SASL authentication step
3: I1111 01:54:26.092988 17489 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '31255769382b' server FQDN: '31255769382b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1111 01:54:26.093004 17489 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1111 01:54:26.093041 17489 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1111 01:54:26.093075 17489 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '31255769382b' server FQDN: '31255769382b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1111 01:54:26.093088 17489 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1111 01:54:26.093097 17489 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1111 01:54:26.093112 17489 authenticator.cpp:318] Authentication success
3: I1111 01:54:26.093190 17495 authenticatee.cpp:299] Authentication success
3: I1111 01:54:26.093242 17496 master.cpp:8316] Successfully authenticated principal 'test-principal' at slave(293)@172.17.0.3:60743
3: I1111 01:54:26.093294 17491 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(615)@172.17.0.3:60743
3: I1111 01:54:26.093487 17495 slave.cpp:1161] Successfully authenticated with master master@172.17.0.3:60743
3: I1111 01:54:26.094033 17495 slave.cpp:1682] Will retry registration in 979503ns if necessary
3: I1111 01:54:26.094697 17485 master.cpp:6351] Received re-register agent message from agent 604719d2-da2d-4af4-a764-0667a6967181-S0 at slave(293)@172.17.0.3:60743 (31255769382b)
+ docker rmi mesos-1510362968-12928
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user yujie.jay@gmail.com