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/22 00:32:38 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) #4488
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)/4488/display/redirect?page=changes>
Changes:
[alexr] Fixed build dependencies in libprocess.
------------------------------------------
[...truncated 25.99 MB...]
3: I1122 00:32:33.144819 18249 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1122 00:32:33.145012 18249 master.cpp:634] Authorization enabled
3: I1122 00:32:33.145252 18252 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1122 00:32:33.145359 18265 whitelist_watcher.cpp:77] No whitelist given
3: I1122 00:32:33.149036 18249 master.cpp:2215] Elected as the leading master!
3: I1122 00:32:33.149067 18249 master.cpp:1695] Recovering from registrar
3: I1122 00:32:33.149260 18268 registrar.cpp:347] Recovering registrar
3: I1122 00:32:33.149947 18268 registrar.cpp:391] Successfully fetched the registry (0B) in 628992ns
3: I1122 00:32:33.150066 18268 registrar.cpp:495] Applied 1 operations in 30723ns; attempting to update the registry
3: I1122 00:32:33.150740 18268 registrar.cpp:552] Successfully updated the registry in 606976ns
3: I1122 00:32:33.150894 18268 registrar.cpp:424] Successfully recovered registrar
3: I1122 00:32:33.151358 18256 master.cpp:1808] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1122 00:32:33.151469 18248 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: I1122 00:32:33.153512 18246 process.cpp:3503] Handling HTTP event for process 'master' with path: '/master/api/v1'
3: I1122 00:32:33.155014 18258 http.cpp:1185] HTTP POST for /master/api/v1 from 172.17.0.2:33156
3: I1122 00:32:33.155156 18258 http.cpp:673] Processing call GET_VERSION
3: I1122 00:32:33.157382 18245 master.cpp:1153] Master terminating
3: [ OK ] ContentType/MasterAPITest.GetVersion/0 (24 ms)
3: [ RUN ] ContentType/MasterAPITest.GetVersion/1
3: I1122 00:32:33.164350 18245 cluster.cpp:162] Creating default 'local' authorizer
3: I1122 00:32:33.168262 18249 master.cpp:448] Master 6ad4b73c-b9b2-4f99-98fb-72efa99da44b (5c0572341899) started on 172.17.0.2:41144
3: I1122 00:32:33.168285 18249 master.cpp:450] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1000secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/MhqCRh/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/MhqCRh/master" --zk_session_timeout="10secs"
3: I1122 00:32:33.168586 18249 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1122 00:32:33.168594 18249 master.cpp:505] Master only allowing authenticated agents to register
3: I1122 00:32:33.168598 18249 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1122 00:32:33.168604 18249 credentials.hpp:37] Loading credentials for authentication from '/tmp/MhqCRh/credentials'
3: I1122 00:32:33.168884 18249 master.cpp:555] Using default 'crammd5' authenticator
3: I1122 00:32:33.169028 18249 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1122 00:32:33.169179 18249 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1122 00:32:33.169327 18249 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1122 00:32:33.169461 18249 master.cpp:634] Authorization enabled
3: I1122 00:32:33.169621 18256 whitelist_watcher.cpp:77] No whitelist given
3: I1122 00:32:33.169693 18250 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1122 00:32:33.173110 18252 master.cpp:2215] Elected as the leading master!
3: I1122 00:32:33.173156 18252 master.cpp:1695] Recovering from registrar
3: I1122 00:32:33.173307 18263 registrar.cpp:347] Recovering registrar
3: I1122 00:32:33.174278 18263 registrar.cpp:391] Successfully fetched the registry (0B) in 900864ns
3: I1122 00:32:33.174458 18263 registrar.cpp:495] Applied 1 operations in 52490ns; attempting to update the registry
3: I1122 00:32:33.175452 18263 registrar.cpp:552] Successfully updated the registry in 897024ns
3: I1122 00:32:33.175645 18263 registrar.cpp:424] Successfully recovered registrar
3: I1122 00:32:33.176242 18257 master.cpp:1808] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1122 00:32:33.176291 18259 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: I1122 00:32:33.179391 18249 process.cpp:3503] Handling HTTP event for process 'master' with path: '/master/api/v1'
3: I1122 00:32:33.181373 18264 http.cpp:1185] HTTP POST for /master/api/v1 from 172.17.0.2:33158
3: I1122 00:32:33.181578 18264 http.cpp:673] Processing call GET_VERSION
3: I1122 00:32:33.184010 18245 master.cpp:1153] Master terminating
3: [ OK ] ContentType/MasterAPITest.GetVersion/1 (26 ms)
3: [ RUN ] ContentType/MasterAPITest.GetMetrics/0
3: I1122 00:32:33.192050 18245 cluster.cpp:162] Creating default 'local' authorizer
3: I1122 00:32:33.196352 18265 master.cpp:448] Master bed8a35c-7fc9-43bb-8227-c5b9eae76a98 (5c0572341899) started on 172.17.0.2:41144
3: I1122 00:32:33.196385 18265 master.cpp:450] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1000secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/GqrDFe/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/GqrDFe/master" --zk_session_timeout="10secs"
3: I1122 00:32:33.196795 18265 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1122 00:32:33.196807 18265 master.cpp:505] Master only allowing authenticated agents to register
3: I1122 00:32:33.196815 18265 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1122 00:32:33.196822 18265 credentials.hpp:37] Loading credentials for authentication from '/tmp/GqrDFe/credentials'
3: I1122 00:32:33.197207 18265 master.cpp:555] Using default 'crammd5' authenticator
3: I1122 00:32:33.197412 18265 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1122 00:32:33.197613 18265 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1122 00:32:33.197809 18265 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1122 00:32:33.197993 18265 master.cpp:634] Authorization enabled
3: I1122 00:32:33.198223 18253 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1122 00:32:33.198289 18256 whitelist_watcher.cpp:77] No whitelist given
3: I1122 00:32:33.202559 18248 master.cpp:2215] Elected as the leading master!
3: I1122 00:32:33.202600 18248 master.cpp:1695] Recovering from registrar
3: I1122 00:32:33.202796 18250 registrar.cpp:347] Recovering registrar
3: I1122 00:32:33.203603 18250 registrar.cpp:391] Successfully fetched the registry (0B) in 750080ns
3: I1122 00:32:33.203743 18250 registrar.cpp:495] Applied 1 operations in 39747ns; attempting to update the registry
3: I1122 00:32:33.204480 18250 registrar.cpp:552] Successfully updated the registry in 663040ns
3: I1122 00:32:33.204635 18250 registrar.cpp:424] Successfully recovered registrar
3: I1122 00:32:33.205106 18261 master.cpp:1808] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1122 00:32:33.205130 18255 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: I1122 00:32:33.211458 18267 process.cpp:3503] Handling HTTP event for process 'master' with path: '/master/api/v1'
3: I1122 00:32:33.213181 18249 http.cpp:1185] HTTP POST for /master/api/v1 from 172.17.0.2:33160
3: I1122 00:32:33.213325 18249 http.cpp:673] Processing call GET_METRICS
3: I1122 00:32:33.227538 18245 master.cpp:1153] Master terminating
3: [ OK ] ContentType/MasterAPITest.GetMetrics/0 (43 ms)
3: [ RUN ] ContentType/MasterAPITest.GetMetrics/1
3: I1122 00:32:33.234613 18245 cluster.cpp:162] Creating default 'local' authorizer
3: I1122 00:32:33.238289 18252 master.cpp:448] Master 87a20305-a6a9-4d43-a367-08c5ce162b8e (5c0572341899) started on 172.17.0.2:41144
3: I1122 00:32:33.238320 18252 master.cpp:450] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1000secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/o0HKzb/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/o0HKzb/master" --zk_session_timeout="10secs"
3: I1122 00:32:33.238729 18252 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1122 00:32:33.238740 18252 master.cpp:505] Master only allowing authenticated agents to register
3: I1122 00:32:33.238745 18252 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1122 00:32:33.238752 18252 credentials.hpp:37] Loading credentials for authentication from '/tmp/o0HKzb/credentials'
3: I1122 00:32:33.239176 18252 master.cpp:555] Using default 'crammd5' authenticator
3: I1122 00:32:33.239367 18252 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1122 00:32:33.239550 18252 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1122 00:32:33.239708 18252 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1122 00:32:33.239853 18252 master.cpp:634] Authorization enabled
3: I1122 00:32:33.240020 18268 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1122 00:32:33.240051 18257 whitelist_watcher.cpp:77] No whitelist given
3: I1122 00:32:33.243593 18263 master.cpp:2215] Elected as the leading master!
3: I1122 00:32:33.243626 18263 master.cpp:1695] Recovering from registrar
3: I1122 00:32:33.243782 18261 registrar.cpp:347] Recovering registrar
3: I1122 00:32:33.244428 18261 registrar.cpp:391] Successfully fetched the registry (0B) in 605184ns
3: I1122 00:32:33.244544 18261 registrar.cpp:495] Applied 1 operations in 33186ns; attempting to update the registry
3: I1122 00:32:33.245172 18261 registrar.cpp:552] Successfully updated the registry in 566016ns
3: I1122 00:32:33.245304 18261 registrar.cpp:424] Successfully recovered registrar
3: I1122 00:32:33.245815 18250 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: I1122 00:32:33.245812 18259 master.cpp:1808] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1122 00:32:33.248152 18252 process.cpp:3503] Handling HTTP event for process 'master' with path: '/master/api/v1'
3: I1122 00:32:33.249665 18269 http.cpp:1185] HTTP POST for /master/api/v1 from 172.17.0.2:33162
3: I1122 00:32:33.249963 18269 http.cpp:673] Processing call GET_METRICS
3: I1122 00:32:33.270376 18245 master.cpp:1153] Master terminating
3: [ OK ] ContentType/MasterAPITest.GetMetrics/1 (43 ms)
3: [ RUN ] ContentType/MasterAPITest.GetExecutors/0
3: I1122 00:32:33.276880 18245 cluster.cpp:162] Creating default 'local' authorizer
3: I1122 00:32:33.280338 18269 master.cpp:448] Master 46c89a9a-0d9e-40a7-86ea-6df195a0a726 (5c0572341899) started on 172.17.0.2:41144
3: I1122 00:32:33.280362 18269 master.cpp:450] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1000secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/MM5Sz8/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/MM5Sz8/master" --zk_session_timeout="10secs"
3: I1122 00:32:33.280762 18269 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1122 00:32:33.280773 18269 master.cpp:505] Master only allowing authenticated agents to register
3: I1122 00:32:33.280779 18269 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1122 00:32:33.280786 18269 credentials.hpp:37] Loading credentials for authentication from '/tmp/MM5Sz8/credentials'
3: I1122 00:32:33.281131 18269 master.cpp:555] Using default 'crammd5' authenticator
3: I1122 00:32:33.281314 18269 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1122 00:32:33.281525 18269 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1122 00:32:33.281700 18269 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1122 00:32:33.281867 18269 master.cpp:634] Authorization enabled
3: I1122 00:32:33.282104 18259 whitelist_watcher.cpp:77] No whitelist given
3: I1122 00:32:33.282119 18254 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1122 00:32:33.285545 18256 master.cpp:2215] Elected as the leading master!
3: I1122 00:32:33.285576 18256 master.cpp:1695] Recovering from registrar
3: I1122 00:32:33.285737 18262 registrar.cpp:347] Recovering registrar
3: I1122 00:32:33.286272 18262 registrar.cpp:391] Successfully fetched the registry (0B) in 493056ns
3: I1122 00:32:33.286367 18262 registrar.cpp:495] Applied 1 operations in 26046ns; attempting to update the registry
3: I1122 00:32:33.286959 18266 registrar.cpp:552] Successfully updated the registry in 515072ns
3: I1122 00:32:33.287140 18266 registrar.cpp:424] Successfully recovered registrar
3: I1122 00:32:33.287587 18261 master.cpp:1808] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1122 00:32:33.287602 18266 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: W1122 00:32:33.293087 18245 process.cpp:2756] Attempted to spawn already running process files@172.17.0.2:41144
3: I1122 00:32:33.293395 18245 cluster.cpp:448] Creating default 'local' authorizer
3: I1122 00:32:33.295717 18255 slave.cpp:262] Mesos agent started on (679)@172.17.0.2:41144
3: I1122 00:32:33.295737 18255 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/ContentType_MasterAPITest_GetExecutors_0_nJXPE2/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/ContentType_MasterAPITest_GetExecutors_0_nJXPE2/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/ContentType_MasterAPITest_GetExecutors_0_nJXPE2/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/ContentType_MasterAPITest_GetExecutors_0_nJXPE2/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ContentType_MasterAPITest_GetExecutors_0_nJXPE2/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/ContentType_MasterAPITest_GetExecutors_0_nJXPE2/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/ContentType_MasterAPITest_GetExecutors_0_nJXPE2" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/ContentType_MasterAPITest_GetExecutors_0_VxFlC5" --zk_session_timeout="10secs"
3: I1122 00:32:33.296218 18255 credentials.hpp:86] Loading credential for authentication from '/tmp/ContentType_MasterAPITest_GetExecutors_0_nJXPE2/credential'
3: I1122 00:32:33.296399 18255 slave.cpp:295] Agent using credential for: test-principal
3: I1122 00:32:33.296416 18255 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_MasterAPITest_GetExecutors_0_nJXPE2/http_credentials'
3: I1122 00:32:33.296694 18255 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1122 00:32:33.296823 18255 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1122 00:32:33.297046 18255 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1122 00:32:33.297142 18255 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1122 00:32:33.297327 18255 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1122 00:32:33.297427 18255 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1122 00:32:33.299175 18255 slave.cpp:593] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1122 00:32:33.299435 18255 slave.cpp:601] Agent attributes: [ ]
3: I1122 00:32:33.299448 18255 slave.cpp:610] Agent hostname: 5c0572341899
3: I1122 00:32:33.299602 18268 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1122 00:32:33.301689 18248 state.cpp:64] Recovering state from '/tmp/ContentType_MasterAPITest_GetExecutors_0_VxFlC5/meta'
3: I1122 00:32:33.302001 18248 task_status_update_manager.cpp:207] Recovering task status update manager
3: I1122 00:32:33.302362 18246 slave.cpp:6443] Finished recovery
3: I1122 00:32:33.303369 18264 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1122 00:32:33.303439 18267 slave.cpp:1007] New master detected at master@172.17.0.2:41144
3: I1122 00:32:33.303530 18267 slave.cpp:1042] Detecting new master
3: I1122 00:32:33.308303 18266 slave.cpp:1069] Authenticating with master master@172.17.0.2:41144
3: I1122 00:32:33.308423 18266 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1122 00:32:33.308773 18250 authenticatee.cpp:121] Creating new client SASL connection
3: I1122 00:32:33.309128 18259 master.cpp:8306] Authenticating slave(679)@172.17.0.2:41144
3: I1122 00:32:33.309259 18254 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1313)@172.17.0.2:41144
3: I1122 00:32:33.309550 18269 authenticator.cpp:98] Creating new server SASL connection
3: I1122 00:32:33.309768 18268 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1122 00:32:33.309792 18268 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1122 00:32:33.309906 18268 authenticator.cpp:204] Received SASL authentication start
3: I1122 00:32:33.309968 18268 authenticator.cpp:326] Authentication requires more steps
3: I1122 00:32:33.310077 18268 authenticatee.cpp:259] Received SASL authentication step
3: I1122 00:32:33.310292 18247 authenticator.cpp:232] Received SASL authentication step
3: I1122 00:32:33.310360 18247 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '5c0572341899' server FQDN: '5c0572341899' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1122 00:32:33.310376 18247 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1122 00:32:33.310427 18247 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1122 00:32:33.310459 18247 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '5c0572341899' server FQDN: '5c0572341899' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1122 00:32:33.310477 18247 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1122 00:32:33.310487 18247 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1122 00:32:33.310510 18247 authenticator.cpp:318] Authentication success
3: I1122 00:32:33.310622 18263 authenticatee.cpp:299] Authentication success
3: I1122 00:32:33.310849 18253 master.cpp:8336] Successfully authenticated principal 'test-principal' at slave(679)@172.17.0.2:41144
3: I1122 00:32:33.310897 18252 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1313)@172.17.0.2:41144
3: I1122 00:32:33.311045 18255 slave.cpp:1161] Successfully authenticated with master master@172.17.0.2:41144
3: I1122 00:32:33.311426 18255 slave.cpp:1682] Will retry registration in 4.509012ms if necessary
3: I1122 00:32:33.311799 18249 master.cpp:6036] Received register agent message from slave(679)@172.17.0.2:41144 (5c0572341899)
3: I1122 00:32:33.312008 18249 master.cpp:3872] Authorizing agent with principal 'test-principal'
3: I1122 00:32:33.312731 18264 master.cpp:6098] Authorized registration of agent at slave(679)@172.17.0.2:41144 (5c0572341899)
3: I1122 00:32:33.312903 18264 master.cpp:6191] Registering agent at slave(679)@172.17.0.2:41144 (5c0572341899) with id 46c89a9a-0d9e-40a7-86ea-6df195a0a726-S0
3: I1122 00:32:33.313586 18267 registrar.cpp:495] Applied 1 operations in 88376ns; attempting to update the registry
3: I1122 00:32:33.314452 18267 registrar.cpp:552] Successfully updated the registry in 765184ns
3: I1122 00:32:33.314733 18259 master.cpp:6240] Admitted agent 46c89a9a-0d9e-40a7-86ea-6df195a0a726-S0 at slave(679)@172.17.0.2:41144 (5c0572341899)
3: I1122 00:32:33.315517 18259 master.cpp:6273] Registered agent 46c89a9a-0d9e-40a7-86ea-6df195a0a726-S0 at slave(679)@172.17.0.2:41144 (5c0572341899) with [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1122 00:32:33.315737 18269 slave.cpp:1207] Registered with master master@172.17.0.2:41144; given agent ID 46c89a9a-0d9e-40a7-86ea-6df195a0a726-S0
3: I1122 00:32:33.315830 18259 task_status_update_manager.cpp:188] Resuming sending task status updates
3: I1122 00:32:33.315886 18257 hierarchical.cpp:600] Added agent 46c89a9a-0d9e-40a7-86ea-6df195a0a726-S0 (5c0572341899) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
3: I1122 00:32:33.316030 18269 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/ContentType_MasterAPITest_GetExecutors_0_VxFlC5/meta/slaves/46c89a9a-0d9e-40a7-86ea-6df195a0a726-S0/slave.info'
3: I1122 00:32:33.316248 18257 hierarchical.cpp:1457] Performed allocation for 1 agents in 168857ns
3: I1122 00:32:33.316409 18269 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: W1122 00:32:33.316537 18245 process.cpp:2756] Attempted to spawn already running process version@172.17.0.2:41144
3: I1122 00:32:33.316604 18269 master.cpp:7085] Received update of agent 46c89a9a-0d9e-40a7-86ea-6df195a0a726-S0 at slave(679)@172.17.0.2:41144 (5c0572341899) with total oversubscribed resources {}
3: I1122 00:32:33.316756 18269 master.cpp:7103] Ignoring update on agent 46c89a9a-0d9e-40a7-86ea-6df195a0a726-S0 at slave(679)@172.17.0.2:41144 (5c0572341899) as it reports no changes
3: I1122 00:32:33.317510 18245 sched.cpp:232] Version: 1.5.0
3: I1122 00:32:33.318188 18264 sched.cpp:336] New master detected at master@172.17.0.2:41144
3: I1122 00:32:33.318333 18264 sched.cpp:396] Authenticating with master master@172.17.0.2:41144
3: I1122 00:32:33.318356 18264 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1122 00:32:33.318748 18251 authenticatee.cpp:121] Creating new client SASL connection
3: I1122 00:32:33.319216 18261 master.cpp:8306] Authenticating scheduler-057c1ae8-0349-4eed-8a92-5957a5620dcf@172.17.0.2:41144
3: I1122 00:32:33.319355 18250 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1314)@172.17.0.2:41144
3: I1122 00:32:33.319591 18267 authenticator.cpp:98] Creating new server SASL connection
3: I1122 00:32:33.319785 18254 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1122 00:32:33.319808 18254 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1122 00:32:33.319906 18263 authenticator.cpp:204] Received SASL authentication start
3: I1122 00:32:33.319952 18263 authenticator.cpp:326] Authentication requires more steps
3: I1122 00:32:33.320039 18263 authenticatee.cpp:259] Received SASL authentication step
3: I1122 00:32:33.320158 18247 authenticator.cpp:232] Received SASL authentication step
3: I1122 00:32:33.320192 18247 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '5c0572341899' server FQDN: '5c0572341899' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1122 00:32:33.320205 18247 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1122 00:32:33.320245 18247 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1122 00:32:33.320266 18247 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '5c0572341899' server FQDN: '5c0572341899' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1122 00:32:33.320277 18247 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1122 00:32:33.320288 18247 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1122 00:32:33.320305 18247 authenticator.cpp:318] Authentication success
3: I1122 00:32:33.320382 18259 authenticatee.cpp:299] Authentication success
3: I1122 00:32:33.320453 18268 master.cpp:8336] Successfully authenticated principal 'test-principal' at scheduler-057c1ae8-0349-4eed-8a92-5957a5620dcf@172.17.0.2:41144
3: I1122 00:32:33.320518 18248 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1314)@172.17.0.2:41144
3: I1122 00:32:33.320672 18260 sched.cpp:502] Successfully authenticated with master master@172.17.0.2:41144
3: I1122 00:32:33.320696 18260 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.2:41144
3: I1122 00:32:33.320818 18260 sched.cpp:857] Will retry registration in 963.094838ms if necessary
3: I1122 00:32:33.321069 18265 master.cpp:2963] Received SUBSCRIBE call for framework 'default' at scheduler-057c1ae8-0349-4eed-8a92-5957a5620dcf@172.17.0.2:41144
3: I1122 00:32:33.321164 18265 master.cpp:2280] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
3: I1122 00:32:33.321789 18255 master.cpp:3043] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1122 00:32:33.322490 18246 sched.cpp:751] Framework registered with 46c89a9a-0d9e-40a7-86ea-6df195a0a726-0000
3: I1122 00:32:33.322554 18246 sched.cpp:765] Scheduler::registered took 36357ns
3: I1122 00:32:33.322718 18249 hierarchical.cpp:306] Added framework 46c89a9a-0d9e-40a7-86ea-6df195a0a726-0000
3: I1122 00:32:33.324309 18249 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.406919ms
3: I1122 00:32:33.324905 18266 master.cpp:8136] Sending 1 offers to framework 46c89a9a-0d9e-40a7-86ea-6df195a0a726-0000 (default) at scheduler-057c1ae8-0349-4eed-8a92-5957a5620dcf@172.17.0.2:41144
3: I1122 00:32:33.325613 18251 sched.cpp:921] Scheduler::resourceOffers took 144153ns
3: I1122 00:32:33.327989 18247 master.cpp:10045] Removing offer 46c89a9a-0d9e-40a7-86ea-6df195a0a726-O0
3: I1122 00:32:33.328205 18247 master.cpp:4230] Processing ACCEPT call for offers: [ 46c89a9a-0d9e-40a7-86ea-6df195a0a726-O0 ] on agent 46c89a9a-0d9e-40a7-86ea-6df195a0a726-S0 at slave(679)@172.17.0.2:41144 (5c0572341899) for framework 46c89a9a-0d9e-40a7-86ea-6df195a0a726-0000 (default) at scheduler-057c1ae8-0349-4eed-8a92-5957a5620dcf@172.17.0.2:41144
3: I1122 00:32:33.328347 18247 master.cpp:3599] Authorizing framework principal 'test-principal' to launch task 1
3: W1122 00:32:33.330461 18257 validation.cpp:1391] 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: W1122 00:32:33.330499 18257 validation.cpp:1403] 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: I1122 00:32:33.331046 18257 master.cpp:10793] Adding task 1 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] on agent 46c89a9a-0d9e-40a7-86ea-6df195a0a726-S0 at slave(679)@172.17.0.2:41144 (5c0572341899)
3: I1122 00:32:33.331710 18257 master.cpp:4978] Launching task 1 of framework 46c89a9a-0d9e-40a7-86ea-6df195a0a726-0000 (default) at scheduler-057c1ae8-0349-4eed-8a92-5957a5620dcf@172.17.0.2:41144 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] on agent 46c89a9a-0d9e-40a7-86ea-6df195a0a726-S0 at slave(679)@172.17.0.2:41144 (5c0572341899)
3: I1122 00:32:33.332365 18269 slave.cpp:1803] Got assigned task '1' for framework 46c89a9a-0d9e-40a7-86ea-6df195a0a726-0000
3: I1122 00:32:33.333016 18269 slave.cpp:2071] Authorizing task '1' for framework 46c89a9a-0d9e-40a7-86ea-6df195a0a726-0000
3: I1122 00:32:33.333073 18269 slave.cpp:7264] Authorizing framework principal 'test-principal' to launch task 1
3: I1122 00:32:33.333889 18252 slave.cpp:2239] Launching task '1' for framework 46c89a9a-0d9e-40a7-86ea-6df195a0a726-0000
3: I1122 00:32:33.334687 18252 paths.cpp:621] Trying to chown '/tmp/ContentType_MasterAPITest_GetExecutors_0_VxFlC5/slaves/46c89a9a-0d9e-40a7-86ea-6df195a0a726-S0/frameworks/46c89a9a-0d9e-40a7-86ea-6df195a0a726-0000/executors/default/runs/16602d08-feca-4439-b207-93706c0b96fe' to user 'mesos'
3: I1122 00:32:33.335005 18252 slave.cpp:7738] Launching executor 'default' of framework 46c89a9a-0d9e-40a7-86ea-6df195a0a726-0000 with resources [] in work directory '/tmp/ContentType_MasterAPITest_GetExecutors_0_VxFlC5/slaves/46c89a9a-0d9e-40a7-86ea-6df195a0a726-S0/frameworks/46c89a9a-0d9e-40a7-86ea-6df195a0a726-0000/executors/default/runs/16602d08-feca-4439-b207-93706c0b96fe'
3: I1122 00:32:33.336385 18252 slave.cpp:2467] Queued task '1' for executor 'default' of framework 46c89a9a-0d9e-40a7-86ea-6df195a0a726-0000
3: I1122 00:32:33.336527 18252 slave.cpp:958] Successfully attached '/tmp/ContentType_MasterAPITest_GetExecutors_0_VxFlC5/slaves/46c89a9a-0d9e-40a7-86ea-6df195a0a726-S0/frameworks/46c89a9a-0d9e-40a7-86ea-6df195a0a726-0000/executors/default/runs/16602d08-feca-4439-b207-93706c0b96fe' to virtual path '/tmp/ContentType_MasterAPITest_GetExecutors_0_VxFlC5/slaves/46c89a9a-0d9e-40a7-86ea-6df195a0a726-S0/frameworks/46c89a9a-0d9e-40a7-86ea-6df195a0a726-0000/executors/default/runs/latest'
3: I1122 00:32:33.336591 18252 slave.cpp:958] Successfully attached '/tmp/ContentType_MasterAPITest_GetExecutors_0_VxFlC5/slaves/46c89a9a-0d9e-40a7-86ea-6df195a0a726-S0/frameworks/46c89a9a-0d9e-40a7-86ea-6df195a0a726-0000/executors/default/runs/16602d08-feca-4439-b207-93706c0b96fe' to virtual path '/frameworks/46c89a9a-0d9e-40a7-86ea-6df195a0a726-0000/executors/default/runs/latest'
3: I1122 00:32:33.336642 18252 slave.cpp:958] Successfully attached '/tmp/ContentType_MasterAPITest_GetExecutors_0_VxFlC5/slaves/46c89a9a-0d9e-40a7-86ea-6df195a0a726-S0/frameworks/46c89a9a-0d9e-40a7-86ea-6df195a0a726-0000/executors/default/runs/16602d08-feca-4439-b207-93706c0b96fe' to virtual path '/tmp/ContentType_MasterAPITest_GetExecutors_0_VxFlC5/slaves/46c89a9a-0d9e-40a7-86ea-6df195a0a726-S0/frameworks/46c89a9a-0d9e-40a7-86ea-6df195a0a726-0000/executors/default/runs/16602d08-feca-4439-b207-93706c0b96fe'
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1511308250-30365
Build step 'Execute shell' marked build as failure
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) #4490
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)/4490/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) #4489
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)/4489/display/redirect?page=changes>
Changes:
[yujie.jay] Added an event to publish resources.
[yujie.jay] Started `LocalResourceProviderDaemon` after obtaining the slave ID.
[yujie.jay] Added an optional `additional_chars` parameter to `http::encode`.
------------------------------------------
[...truncated 20.78 MB...]
3: I1122 05:26:14.910640 18316 master.cpp:8306] Authenticating scheduler-0cc18b0c-81c2-40e8-b795-8e0aa8e58f73@172.17.0.4:39249
3: I1122 05:26:14.910748 18304 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1056)@172.17.0.4:39249
3: I1122 05:26:14.910987 18296 authenticator.cpp:98] Creating new server SASL connection
3: I1122 05:26:14.911216 18310 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1122 05:26:14.911248 18310 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1122 05:26:14.911396 18315 authenticator.cpp:204] Received SASL authentication start
3: I1122 05:26:14.911460 18315 authenticator.cpp:326] Authentication requires more steps
3: I1122 05:26:14.911572 18305 authenticatee.cpp:259] Received SASL authentication step
3: I1122 05:26:14.911706 18312 authenticator.cpp:232] Received SASL authentication step
3: I1122 05:26:14.911734 18298 state.cpp:64] Recovering state from '/tmp/ReservationTest_ReserveShareWithinRole_AVnQlM/meta'
3: I1122 05:26:14.911736 18312 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '441d7a7e00ba' server FQDN: '441d7a7e00ba' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1122 05:26:14.911761 18312 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1122 05:26:14.911798 18312 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1122 05:26:14.911818 18312 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '441d7a7e00ba' server FQDN: '441d7a7e00ba' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1122 05:26:14.911829 18312 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1122 05:26:14.911835 18312 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1122 05:26:14.911847 18312 authenticator.cpp:318] Authentication success
3: I1122 05:26:14.911942 18297 authenticatee.cpp:299] Authentication success
3: I1122 05:26:14.912032 18298 task_status_update_manager.cpp:207] Recovering task status update manager
3: I1122 05:26:14.912050 18313 master.cpp:8336] Successfully authenticated principal 'test-principal' at scheduler-0cc18b0c-81c2-40e8-b795-8e0aa8e58f73@172.17.0.4:39249
3: I1122 05:26:14.912089 18306 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1056)@172.17.0.4:39249
3: I1122 05:26:14.912176 18299 sched.cpp:502] Successfully authenticated with master master@172.17.0.4:39249
3: I1122 05:26:14.912194 18299 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.4:39249
3: I1122 05:26:14.912228 18316 containerizer.cpp:668] Recovering containerizer
3: I1122 05:26:14.912292 18299 sched.cpp:857] Will retry registration in 1.927559358secs if necessary
3: I1122 05:26:14.912457 18304 master.cpp:2963] Received SUBSCRIBE call for framework 'framework2' at scheduler-0cc18b0c-81c2-40e8-b795-8e0aa8e58f73@172.17.0.4:39249
3: I1122 05:26:14.912539 18304 master.cpp:2280] Authorizing framework principal 'test-principal' to receive offers for roles '{ role }'
3: I1122 05:26:14.913008 18300 master.cpp:3043] Subscribing framework framework2 with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1122 05:26:14.913543 18298 sched.cpp:751] Framework registered with bae28168-4f3c-460c-8d11-184dfcaf5550-0000
3: I1122 05:26:14.913591 18298 sched.cpp:765] Scheduler::registered took 25329ns
3: I1122 05:26:14.913599 18313 provisioner.cpp:455] Provisioner recovery complete
3: I1122 05:26:14.913714 18318 hierarchical.cpp:306] Added framework bae28168-4f3c-460c-8d11-184dfcaf5550-0000
3: I1122 05:26:14.913915 18317 slave.cpp:6449] Finished recovery
3: I1122 05:26:14.913918 18318 hierarchical.cpp:1457] Performed allocation for 0 agents in 59629ns
3: I1122 05:26:14.914505 18299 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1122 05:26:14.914525 18317 slave.cpp:1007] New master detected at master@172.17.0.4:39249
3: I1122 05:26:14.914575 18317 slave.cpp:1042] Detecting new master
3: I1122 05:26:14.915815 18310 hierarchical.cpp:1457] Performed allocation for 0 agents in 51185ns
3: I1122 05:26:14.921975 18305 slave.cpp:1069] Authenticating with master master@172.17.0.4:39249
3: I1122 05:26:14.922039 18305 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1122 05:26:14.922134 18302 hierarchical.cpp:1457] Performed allocation for 0 agents in 50280ns
3: I1122 05:26:14.922212 18301 authenticatee.cpp:121] Creating new client SASL connection
3: I1122 05:26:14.922437 18316 master.cpp:8306] Authenticating slave(522)@172.17.0.4:39249
3: I1122 05:26:14.922585 18303 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1057)@172.17.0.4:39249
3: I1122 05:26:14.922963 18297 authenticator.cpp:98] Creating new server SASL connection
3: I1122 05:26:14.923374 18312 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1122 05:26:14.923413 18312 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1122 05:26:14.923528 18312 authenticator.cpp:204] Received SASL authentication start
3: I1122 05:26:14.923599 18312 authenticator.cpp:326] Authentication requires more steps
3: I1122 05:26:14.923755 18300 authenticatee.cpp:259] Received SASL authentication step
3: I1122 05:26:14.923861 18300 authenticator.cpp:232] Received SASL authentication step
3: I1122 05:26:14.923892 18300 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '441d7a7e00ba' server FQDN: '441d7a7e00ba' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1122 05:26:14.923903 18300 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1122 05:26:14.923928 18300 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1122 05:26:14.923943 18300 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '441d7a7e00ba' server FQDN: '441d7a7e00ba' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1122 05:26:14.923950 18300 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1122 05:26:14.923955 18300 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1122 05:26:14.923966 18300 authenticator.cpp:318] Authentication success
3: I1122 05:26:14.924041 18315 authenticatee.cpp:299] Authentication success
3: I1122 05:26:14.924085 18308 master.cpp:8336] Successfully authenticated principal 'test-principal' at slave(522)@172.17.0.4:39249
3: I1122 05:26:14.924142 18311 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1057)@172.17.0.4:39249
3: I1122 05:26:14.924320 18298 slave.cpp:1161] Successfully authenticated with master master@172.17.0.4:39249
3: I1122 05:26:14.924538 18298 slave.cpp:1685] Will retry registration in 9.891181ms if necessary
3: I1122 05:26:14.924906 18318 master.cpp:6036] Received register agent message from slave(522)@172.17.0.4:39249 (441d7a7e00ba)
3: I1122 05:26:14.925077 18318 master.cpp:3872] Authorizing agent with principal 'test-principal'
3: I1122 05:26:14.925498 18299 master.cpp:6098] Authorized registration of agent at slave(522)@172.17.0.4:39249 (441d7a7e00ba)
3: I1122 05:26:14.925593 18299 master.cpp:6191] Registering agent at slave(522)@172.17.0.4:39249 (441d7a7e00ba) with id bae28168-4f3c-460c-8d11-184dfcaf5550-S0
3: I1122 05:26:14.925992 18295 registrar.cpp:495] Applied 1 operations in 59818ns; attempting to update the registry
3: I1122 05:26:14.926524 18295 registrar.cpp:552] Successfully updated the registry in 484096ns
3: I1122 05:26:14.926735 18302 master.cpp:6240] Admitted agent bae28168-4f3c-460c-8d11-184dfcaf5550-S0 at slave(522)@172.17.0.4:39249 (441d7a7e00ba)
3: I1122 05:26:14.927422 18316 slave.cpp:1207] Registered with master master@172.17.0.4:39249; given agent ID bae28168-4f3c-460c-8d11-184dfcaf5550-S0
3: I1122 05:26:14.927527 18304 task_status_update_manager.cpp:188] Resuming sending task status updates
3: I1122 05:26:14.927341 18302 master.cpp:6273] Registered agent bae28168-4f3c-460c-8d11-184dfcaf5550-S0 at slave(522)@172.17.0.4:39249 (441d7a7e00ba) with [{"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":512.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":367489.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1122 05:26:14.927687 18303 hierarchical.cpp:600] Added agent bae28168-4f3c-460c-8d11-184dfcaf5550-S0 (441d7a7e00ba) with cpus:1; mem:512; disk:367489; ports:[31000-32000] (allocated: {})
3: I1122 05:26:14.927754 18316 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/ReservationTest_ReserveShareWithinRole_AVnQlM/meta/slaves/bae28168-4f3c-460c-8d11-184dfcaf5550-S0/slave.info'
3: I1122 05:26:14.928184 18316 slave.cpp:1298] Forwarding total oversubscribed resources {}
3: I1122 05:26:14.928381 18316 master.cpp:7085] Received update of agent bae28168-4f3c-460c-8d11-184dfcaf5550-S0 at slave(522)@172.17.0.4:39249 (441d7a7e00ba) with total oversubscribed resources {}
3: I1122 05:26:14.928539 18316 master.cpp:7103] Ignoring update on agent bae28168-4f3c-460c-8d11-184dfcaf5550-S0 at slave(522)@172.17.0.4:39249 (441d7a7e00ba) as it reports no changes
3: I1122 05:26:14.928872 18303 hierarchical.cpp:1457] Performed allocation for 1 agents in 969891ns
3: I1122 05:26:14.929280 18300 master.cpp:8136] Sending 1 offers to framework bae28168-4f3c-460c-8d11-184dfcaf5550-0000 (framework2) at scheduler-0cc18b0c-81c2-40e8-b795-8e0aa8e58f73@172.17.0.4:39249
3: I1122 05:26:14.929739 18315 sched.cpp:921] Scheduler::resourceOffers took 95508ns
3: I1122 05:26:14.931145 18307 master.cpp:10045] Removing offer bae28168-4f3c-460c-8d11-184dfcaf5550-O0
3: I1122 05:26:14.931282 18307 master.cpp:4230] Processing ACCEPT call for offers: [ bae28168-4f3c-460c-8d11-184dfcaf5550-O0 ] on agent bae28168-4f3c-460c-8d11-184dfcaf5550-S0 at slave(522)@172.17.0.4:39249 (441d7a7e00ba) for framework bae28168-4f3c-460c-8d11-184dfcaf5550-0000 (framework2) at scheduler-0cc18b0c-81c2-40e8-b795-8e0aa8e58f73@172.17.0.4:39249
3: I1122 05:26:14.931412 18307 master.cpp:3657] Authorizing principal 'test-principal' to reserve resources '[{"allocation_info":{"role":"role"},"name":"cpus","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"role"},"name":"mem","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":512.0},"type":"SCALAR"}]'
3: I1122 05:26:14.932807 18305 master.cpp:4563] Applying RESERVE operation for resources [{"allocation_info":{"role":"role"},"name":"cpus","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"role"},"name":"mem","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":512.0},"type":"SCALAR"}] from framework bae28168-4f3c-460c-8d11-184dfcaf5550-0000 (framework2) at scheduler-0cc18b0c-81c2-40e8-b795-8e0aa8e58f73@172.17.0.4:39249 to agent bae28168-4f3c-460c-8d11-184dfcaf5550-S0 at slave(522)@172.17.0.4:39249 (441d7a7e00ba)
3: I1122 05:26:14.933449 18305 master.cpp:9990] Sending updated checkpointed resources cpus(reservations: [(DYNAMIC,role,test-principal)]):1; mem(reservations: [(DYNAMIC,role,test-principal)]):512 to agent bae28168-4f3c-460c-8d11-184dfcaf5550-S0 at slave(522)@172.17.0.4:39249 (441d7a7e00ba)
3: I1122 05:26:14.934234 18301 slave.cpp:3590] Updated checkpointed resources from {} to cpus(reservations: [(DYNAMIC,role,test-principal)]):1; mem(reservations: [(DYNAMIC,role,test-principal)]):512
3: I1122 05:26:14.936030 18297 hierarchical.cpp:856] Updated allocation of framework bae28168-4f3c-460c-8d11-184dfcaf5550-0000 on agent bae28168-4f3c-460c-8d11-184dfcaf5550-S0 from cpus(allocated: role):1; mem(allocated: role):512; disk(allocated: role):367489; ports(allocated: role):[31000-32000] to ports(allocated: role):[31000-32000]; cpus(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):1; disk(allocated: role):367489; mem(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):512
3: I1122 05:26:14.937106 18297 hierarchical.cpp:1132] Recovered ports(allocated: role):[31000-32000]; cpus(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):1; disk(allocated: role):367489; mem(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):512 (total: ports:[31000-32000]; cpus(reservations: [(DYNAMIC,role,test-principal)]):1; disk:367489; mem(reservations: [(DYNAMIC,role,test-principal)]):512, allocated: {}) on agent bae28168-4f3c-460c-8d11-184dfcaf5550-S0 from framework bae28168-4f3c-460c-8d11-184dfcaf5550-0000
3: I1122 05:26:14.938459 18297 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.134287ms
3: I1122 05:26:14.939018 18304 master.cpp:8136] Sending 1 offers to framework bae28168-4f3c-460c-8d11-184dfcaf5550-0000 (framework2) at scheduler-0cc18b0c-81c2-40e8-b795-8e0aa8e58f73@172.17.0.4:39249
3: I1122 05:26:14.939680 18302 sched.cpp:921] Scheduler::resourceOffers took 173376ns
3: I1122 05:26:14.940343 18300 master.cpp:5434] Processing DECLINE call for offers: [ bae28168-4f3c-460c-8d11-184dfcaf5550-O1 ] for framework bae28168-4f3c-460c-8d11-184dfcaf5550-0000 (framework2) at scheduler-0cc18b0c-81c2-40e8-b795-8e0aa8e58f73@172.17.0.4:39249
3: I1122 05:26:14.940665 18294 sched.cpp:232] Version: 1.5.0
3: I1122 05:26:14.940939 18300 master.cpp:10045] Removing offer bae28168-4f3c-460c-8d11-184dfcaf5550-O1
3: I1122 05:26:14.941179 18311 sched.cpp:336] New master detected at master@172.17.0.4:39249
3: I1122 05:26:14.941270 18311 sched.cpp:396] Authenticating with master master@172.17.0.4:39249
3: I1122 05:26:14.941290 18311 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1122 05:26:14.941488 18299 authenticatee.cpp:121] Creating new client SASL connection
3: I1122 05:26:14.941570 18313 hierarchical.cpp:1132] Recovered ports(allocated: role):[31000-32000]; cpus(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):1; disk(allocated: role):367489; mem(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):512 (total: ports:[31000-32000]; cpus(reservations: [(DYNAMIC,role,test-principal)]):1; disk:367489; mem(reservations: [(DYNAMIC,role,test-principal)]):512, allocated: {}) on agent bae28168-4f3c-460c-8d11-184dfcaf5550-S0 from framework bae28168-4f3c-460c-8d11-184dfcaf5550-0000
3: W1122 05:26:14.941637 18313 hierarchical.cpp:1153] Using 365 days to create the refused resources offer filter because the input value is too big
3: I1122 05:26:14.941671 18313 hierarchical.cpp:1178] Framework bae28168-4f3c-460c-8d11-184dfcaf5550-0000 filtered agent bae28168-4f3c-460c-8d11-184dfcaf5550-S0 for 365days
3: I1122 05:26:14.941720 18296 master.cpp:8306] Authenticating scheduler-59461bb5-388b-42dc-ab94-dafb770945e5@172.17.0.4:39249
3: I1122 05:26:14.941807 18307 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1058)@172.17.0.4:39249
3: I1122 05:26:14.941998 18317 authenticator.cpp:98] Creating new server SASL connection
3: I1122 05:26:14.942237 18295 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1122 05:26:14.942261 18295 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1122 05:26:14.942363 18305 authenticator.cpp:204] Received SASL authentication start
3: I1122 05:26:14.942417 18305 authenticator.cpp:326] Authentication requires more steps
3: I1122 05:26:14.942503 18305 authenticatee.cpp:259] Received SASL authentication step
3: I1122 05:26:14.942612 18297 authenticator.cpp:232] Received SASL authentication step
3: I1122 05:26:14.942638 18297 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '441d7a7e00ba' server FQDN: '441d7a7e00ba' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1122 05:26:14.942646 18297 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1122 05:26:14.942677 18297 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1122 05:26:14.942693 18297 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '441d7a7e00ba' server FQDN: '441d7a7e00ba' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1122 05:26:14.942703 18297 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1122 05:26:14.942708 18297 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1122 05:26:14.942719 18297 authenticator.cpp:318] Authentication success
3: I1122 05:26:14.942811 18304 authenticatee.cpp:299] Authentication success
3: I1122 05:26:14.942844 18316 master.cpp:8336] Successfully authenticated principal 'test-principal' at scheduler-59461bb5-388b-42dc-ab94-dafb770945e5@172.17.0.4:39249
3: I1122 05:26:14.942878 18302 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1058)@172.17.0.4:39249
3: I1122 05:26:14.943066 18312 sched.cpp:502] Successfully authenticated with master master@172.17.0.4:39249
3: I1122 05:26:14.943089 18312 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.4:39249
3: I1122 05:26:14.943195 18312 sched.cpp:857] Will retry registration in 465.535723ms if necessary
3: I1122 05:26:14.943349 18308 master.cpp:2963] Received SUBSCRIBE call for framework 'default' at scheduler-59461bb5-388b-42dc-ab94-dafb770945e5@172.17.0.4:39249
3: I1122 05:26:14.943419 18308 master.cpp:2280] Authorizing framework principal 'test-principal' to receive offers for roles '{ role }'
3: I1122 05:26:14.943789 18298 master.cpp:3043] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1122 05:26:14.944401 18298 sched.cpp:751] Framework registered with bae28168-4f3c-460c-8d11-184dfcaf5550-0001
3: I1122 05:26:14.944447 18298 sched.cpp:765] Scheduler::registered took 18072ns
3: I1122 05:26:14.944677 18318 hierarchical.cpp:2175] Filtered offer with ports:[31000-32000]; cpus(reservations: [(DYNAMIC,role,test-principal)]):1; disk:367489; mem(reservations: [(DYNAMIC,role,test-principal)]):512 on agent bae28168-4f3c-460c-8d11-184dfcaf5550-S0 for role role of framework bae28168-4f3c-460c-8d11-184dfcaf5550-0000
3: I1122 05:26:14.944857 18318 hierarchical.cpp:1457] Performed allocation for 1 agents in 884473ns
3: I1122 05:26:14.945349 18318 hierarchical.cpp:306] Added framework bae28168-4f3c-460c-8d11-184dfcaf5550-0001
3: I1122 05:26:14.947867 18318 hierarchical.cpp:1457] Performed allocation for 1 agents in 2.307727ms
3: I1122 05:26:14.948374 18309 master.cpp:8136] Sending 1 offers to framework bae28168-4f3c-460c-8d11-184dfcaf5550-0001 (default) at scheduler-59461bb5-388b-42dc-ab94-dafb770945e5@172.17.0.4:39249
3: I1122 05:26:14.948828 18311 sched.cpp:921] Scheduler::resourceOffers took 102670ns
3: I1122 05:26:14.949228 18294 sched.cpp:2009] Asked to stop the driver
3: I1122 05:26:14.949308 18307 sched.cpp:1191] Stopping framework bae28168-4f3c-460c-8d11-184dfcaf5550-0000
3: I1122 05:26:14.949501 18295 master.cpp:8813] Processing TEARDOWN call for framework bae28168-4f3c-460c-8d11-184dfcaf5550-0000 (framework2) at scheduler-0cc18b0c-81c2-40e8-b795-8e0aa8e58f73@172.17.0.4:39249
3: I1122 05:26:14.949527 18295 master.cpp:8825] Removing framework bae28168-4f3c-460c-8d11-184dfcaf5550-0000 (framework2) at scheduler-0cc18b0c-81c2-40e8-b795-8e0aa8e58f73@172.17.0.4:39249
3: I1122 05:26:14.949538 18295 master.cpp:3333] Deactivating framework bae28168-4f3c-460c-8d11-184dfcaf5550-0000 (framework2) at scheduler-0cc18b0c-81c2-40e8-b795-8e0aa8e58f73@172.17.0.4:39249
3: I1122 05:26:14.949581 18294 sched.cpp:2009] Asked to stop the driver
3: I1122 05:26:14.949635 18317 hierarchical.cpp:419] Deactivated framework bae28168-4f3c-460c-8d11-184dfcaf5550-0000
3: I1122 05:26:14.949723 18303 sched.cpp:1191] Stopping framework bae28168-4f3c-460c-8d11-184dfcaf5550-0001
3: I1122 05:26:14.949723 18304 slave.cpp:3270] Asked to shut down framework bae28168-4f3c-460c-8d11-184dfcaf5550-0000 by master@172.17.0.4:39249
3: I1122 05:26:14.949779 18304 slave.cpp:3285] Cannot shut down unknown framework bae28168-4f3c-460c-8d11-184dfcaf5550-0000
3: I1122 05:26:14.949884 18314 hierarchical.cpp:358] Removed framework bae28168-4f3c-460c-8d11-184dfcaf5550-0000
3: I1122 05:26:14.949970 18316 master.cpp:8813] Processing TEARDOWN call for framework bae28168-4f3c-460c-8d11-184dfcaf5550-0001 (default) at scheduler-59461bb5-388b-42dc-ab94-dafb770945e5@172.17.0.4:39249
3: I1122 05:26:14.949997 18316 master.cpp:8825] Removing framework bae28168-4f3c-460c-8d11-184dfcaf5550-0001 (default) at scheduler-59461bb5-388b-42dc-ab94-dafb770945e5@172.17.0.4:39249
3: I1122 05:26:14.950007 18316 master.cpp:3333] Deactivating framework bae28168-4f3c-460c-8d11-184dfcaf5550-0001 (default) at scheduler-59461bb5-388b-42dc-ab94-dafb770945e5@172.17.0.4:39249
3: I1122 05:26:14.950109 18312 hierarchical.cpp:419] Deactivated framework bae28168-4f3c-460c-8d11-184dfcaf5550-0001
3: I1122 05:26:14.950598 18316 master.cpp:10045] Removing offer bae28168-4f3c-460c-8d11-184dfcaf5550-O2
3: I1122 05:26:14.950759 18318 slave.cpp:3270] Asked to shut down framework bae28168-4f3c-460c-8d11-184dfcaf5550-0001 by master@172.17.0.4:39249
3: I1122 05:26:14.950784 18318 slave.cpp:3285] Cannot shut down unknown framework bae28168-4f3c-460c-8d11-184dfcaf5550-0001
3: I1122 05:26:14.951236 18308 hierarchical.cpp:1132] Recovered ports(allocated: role):[31000-32000]; cpus(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):1; disk(allocated: role):367489; mem(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):512 (total: ports:[31000-32000]; cpus(reservations: [(DYNAMIC,role,test-principal)]):1; disk:367489; mem(reservations: [(DYNAMIC,role,test-principal)]):512, allocated: {}) on agent bae28168-4f3c-460c-8d11-184dfcaf5550-S0 from framework bae28168-4f3c-460c-8d11-184dfcaf5550-0001
3: I1122 05:26:14.951525 18308 hierarchical.cpp:358] Removed framework bae28168-4f3c-460c-8d11-184dfcaf5550-0001
3: I1122 05:26:14.951606 18301 slave.cpp:883] Agent terminating
3: I1122 05:26:14.951757 18312 master.cpp:1311] Agent bae28168-4f3c-460c-8d11-184dfcaf5550-S0 at slave(522)@172.17.0.4:39249 (441d7a7e00ba) disconnected
3: I1122 05:26:14.951778 18312 master.cpp:3370] Disconnecting agent bae28168-4f3c-460c-8d11-184dfcaf5550-S0 at slave(522)@172.17.0.4:39249 (441d7a7e00ba)
3: I1122 05:26:14.951820 18312 master.cpp:3389] Deactivating agent bae28168-4f3c-460c-8d11-184dfcaf5550-S0 at slave(522)@172.17.0.4:39249 (441d7a7e00ba)
3: I1122 05:26:14.951915 18316 hierarchical.cpp:697] Agent bae28168-4f3c-460c-8d11-184dfcaf5550-S0 deactivated
3: I1122 05:26:14.952639 18310 hierarchical.cpp:1457] Performed allocation for 1 agents in 132495ns
3: I1122 05:26:14.959959 18294 master.cpp:1153] Master terminating
3: I1122 05:26:14.960698 18316 hierarchical.cpp:633] Removed agent bae28168-4f3c-460c-8d11-184dfcaf5550-S0
3: I1122 05:26:14.960911 18316 hierarchical.cpp:1457] Performed allocation for 0 agents in 55329ns
3: [ OK ] ReservationTest.ReserveShareWithinRole (80 ms)
3: [ RUN ] ReservationTest.DropReserveTooLarge
3: I1122 05:26:14.969665 18294 cluster.cpp:162] Creating default 'local' authorizer
3: I1122 05:26:14.973646 18316 master.cpp:448] Master 9bd9a95b-4846-4bb7-9a84-345b2c2bb223 (441d7a7e00ba) started on 172.17.0.4:39249
3: I1122 05:26:14.973668 18316 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/blNDPj/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/blNDPj/master" --zk_session_timeout="10secs"
3: I1122 05:26:14.973978 18316 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1122 05:26:14.973985 18316 master.cpp:505] Master only allowing authenticated agents to register
3: I1122 05:26:14.973989 18316 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1122 05:26:14.973995 18316 credentials.hpp:37] Loading credentials for authentication from '/tmp/blNDPj/credentials'
3: I1122 05:26:14.974270 18316 master.cpp:555] Using default 'crammd5' authenticator
3: I1122 05:26:14.974406 18316 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1122 05:26:14.974551 18316 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1122 05:26:14.974670 18316 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1122 05:26:14.974797 18316 master.cpp:634] Authorization enabled
3: W1122 05:26:14.974810 18316 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: I1122 05:26:14.975021 18304 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1122 05:26:14.975051 18309 whitelist_watcher.cpp:77] No whitelist given
3: I1122 05:26:14.978873 18298 master.cpp:2215] Elected as the leading master!
3: I1122 05:26:14.978927 18298 master.cpp:1695] Recovering from registrar
3: I1122 05:26:14.979251 18317 registrar.cpp:347] Recovering registrar
3: I1122 05:26:14.980207 18317 registrar.cpp:391] Successfully fetched the registry (0B) in 887040ns
3: I1122 05:26:14.980361 18317 registrar.cpp:495] Applied 1 operations in 43347ns; attempting to update the registry
3: I1122 05:26:14.980445 18305 hierarchical.cpp:1457] Performed allocation for 0 agents in 41301ns
3: I1122 05:26:14.981220 18317 registrar.cpp:552] Successfully updated the registry in 775168ns
3: I1122 05:26:14.981408 18317 registrar.cpp:424] Successfully recovered registrar
3: I1122 05:26:14.982028 18310 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: I1122 05:26:14.982025 18315 master.cpp:1808] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1122 05:26:14.986515 18304 hierarchical.cpp:1457] Performed allocation for 0 agents in 34864ns
3: W1122 05:26:14.989728 18294 process.cpp:2756] Attempted to spawn already running process files@172.17.0.4:39249
3: I1122 05:26:14.990844 18294 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1122 05:26:14.991549 18294 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1122 05:26:14.991703 18294 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1122 05:26:14.991753 18294 provisioner.cpp:259] Using default backend 'copy'
3: I1122 05:26:14.991988 18311 hierarchical.cpp:1457] Performed allocation for 0 agents in 34778ns
3: I1122 05:26:14.994154 18294 cluster.cpp:448] Creating default 'local' authorizer
3: I1122 05:26:14.996862 18304 slave.cpp:262] Mesos agent started on (523)@172.17.0.4:39249
3: I1122 05:26:14.996882 18304 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/ReservationTest_DropReserveTooLarge_5UEk6k/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_DropReserveTooLarge_5UEk6k/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_DropReserveTooLarge_5UEk6k/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_DropReserveTooLarge_5UEk6k/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ReservationTest_DropReserveTooLarge_5UEk6k/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_DropReserveTooLarge_5UEk6k/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:1;mem:512" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/ReservationTest_DropReserveTooLarge_5UEk6k" --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_DropReserveTooLarge_bkgYsP" --zk_session_timeout="10secs"
3: I1122 05:26:14.997289 18304 credentials.hpp:86] Loading credential for authentication from '/tmp/ReservationTest_DropReserveTooLarge_5UEk6k/credential'
3: W1122 05:26:14.997375 18294 process.cpp:2756] Attempted to spawn already running process version@172.17.0.4:39249
3: I1122 05:26:14.997460 18304 slave.cpp:295] Agent using credential for: test-principal
3: I1122 05:26:14.997480 18304 credentials.hpp:37] Loading credentials for authentication from '/tmp/ReservationTest_DropReserveTooLarge_5UEk6k/http_credentials'
3: I1122 05:26:14.997766 18304 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1122 05:26:14.997880 18304 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1122 05:26:14.998101 18304 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1122 05:26:14.998198 18304 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1122 05:26:14.998420 18304 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1122 05:26:14.998538 18304 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1122 05:26:14.998594 18294 sched.cpp:232] Version: 1.5.0
3: I1122 05:26:14.999058 18306 sched.cpp:336] New master detected at master@172.17.0.4:39249
3: I1122 05:26:14.999274 18306 sched.cpp:396] Authenticating with master master@172.17.0.4:39249
3: I1122 05:26:14.999302 18306 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1122 05:26:14.999608 18315 authenticatee.cpp:121] Creating new client SASL connection
3: I1122 05:26:14.999972 18296 master.cpp:8306] Authenticating scheduler-d661bbf9-d512-45c4-a395-ba728cc187c2@172.17.0.4:39249
3: I1122 05:26:15.000073 18307 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1059)@172.17.0.4:39249
3: I1122 05:26:14.999919 18304 slave.cpp:593] Agent resources: [{"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":512.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":367489.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1122 05:26:15.000164 18304 slave.cpp:601] Agent attributes: [ ]
3: I1122 05:26:15.000174 18304 slave.cpp:610] Agent hostname: 441d7a7e00ba
3: I1122 05:26:15.000304 18311 authenticator.cpp:98] Creating new server SASL connection
3: I1122 05:26:15.000412 18298 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1122 05:26:15.000424 18318 hierarchical.cpp:1457] Performed allocation for 0 agents in 35447ns
3: I1122 05:26:15.000515 18313 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1122 05:26:15.000547 18313 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1122 05:26:15.000650 18318 authenticator.cpp:204] Received SASL authentication start
3: I1122 05:26:15.000705 18318 authenticator.cpp:326] Authentication requires more steps
3: I1122 05:26:15.000809 18305 authenticatee.cpp:259] Received SASL authentication step
3: I1122 05:26:15.000936 18299 authenticator.cpp:232] Received SASL authentication step
3: I1122 05:26:15.000963 18299 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '441d7a7e00ba' server FQDN: '441d7a7e00ba' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1122 05:26:15.000972 18299 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1122 05:26:15.000999 18299 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1122 05:26:15.001018 18299 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '441d7a7e00ba' server FQDN: '441d7a7e00ba' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1122 05:26:15.001029 18299 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1122 05:26:15.001034 18299 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1122 05:26:15.001045 18299 authenticator.cpp:318] Authentication success
3: I1122 05:26:15.001201 18302 authenticatee.cpp:299] Authentication success
3: I1122 05:26:15.001222 18309 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1059)@172.17.0.4:39249
3: I1122 05:26:15.001353 18314 master.cpp:8336] Successfully authenticated principal 'test-principal' at scheduler-d661bbf9-d512-45c4-a395-ba728cc187c2@172.17.0.4:39249
3: I1122 05:26:15.001608 18317 sched.cpp:502] Successfully authenticated with master master@172.17.0.4:39249
3: I1122 05:26:15.001629 18317 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.4:39249
3: I1122 05:26:15.001724 18317 sched.cpp:857] Will retry registration in 1.729723578secs if necessary
3: I1122 05:26:15.001911 18300 master.cpp:2963] Received SUBSCRIBE call for framework 'default' at scheduler-d661bbf9-d512-45c4-a395-ba728cc187c2@172.17.0.4:39249
3: I1122 05:26:15.001993 18300 master.cpp:2280] Authorizing framework principal 'test-principal' to receive offers for roles '{ role }'
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1511326391-22979
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user yujie.jay@gmail.com