mesos-builds mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4445
Date Sat, 11 Nov 2017 06:54:58 GMT
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4445/display/redirect>

------------------------------------------
[...truncated 13.75 MB...]
3: I1111 06:54:43.950383 17262 slave.cpp:4053] Got registration for executor 'test-executor'
of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 from executor(115)@172.17.0.2:46580
3: I1111 06:54:43.950856 17270 exec.cpp:237] Executor registered on agent f087df97-96b4-4cc9-b99a-a36b74462017-S0
3: I1111 06:54:43.950908 17270 exec.cpp:249] Executor::registered took 25170ns
3: I1111 06:54:43.951380 17262 slave.cpp:2669] Sending queued task '1' to executor 'test-executor'
of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 at executor(115)@172.17.0.2:46580
3: I1111 06:54:43.951823 17262 exec.cpp:331] Executor asked to run task '1'
3: I1111 06:54:43.951958 17262 exec.cpp:340] Executor::launchTask took 110717ns
3: I1111 06:54:43.952069 17262 exec.cpp:571] Executor sending status update TASK_RUNNING (UUID:
cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.952383 17261 slave.cpp:4507] Handling status update TASK_RUNNING (UUID:
cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
from executor(115)@172.17.0.2:46580
3: I1111 06:54:43.953101 17266 status_update_manager.cpp:323] Received status update TASK_RUNNING
(UUID: cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.953153 17266 status_update_manager.cpp:500] Creating StatusUpdate stream
for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.953625 17266 status_update_manager.cpp:377] Forwarding update TASK_RUNNING
(UUID: cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
to the agent
3: I1111 06:54:43.953838 17269 slave.cpp:4988] Forwarding the update TASK_RUNNING (UUID: cda3c057-1ba3-47a7-8d61-4a8cef1c2171)
for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 to master@172.17.0.2:46580
3: I1111 06:54:43.954043 17269 slave.cpp:4882] Status update manager successfully handled
status update TASK_RUNNING (UUID: cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework
f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.954088 17269 slave.cpp:4898] Sending acknowledgement for status update TASK_RUNNING
(UUID: cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
to executor(115)@172.17.0.2:46580
3: I1111 06:54:43.954210 17258 master.cpp:7248] Status update TASK_RUNNING (UUID: cda3c057-1ba3-47a7-8d61-4a8cef1c2171)
for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 from agent f087df97-96b4-4cc9-b99a-a36b74462017-S0
at slave(299)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:43.954277 17259 exec.cpp:388] Executor received status update acknowledgement
cda3c057-1ba3-47a7-8d61-4a8cef1c2171 for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.954274 17258 master.cpp:7310] Forwarding status update TASK_RUNNING (UUID:
cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.954500 17258 master.cpp:9503] Updating the state of task 1 of framework
f087df97-96b4-4cc9-b99a-a36b74462017-0000 (latest state: TASK_RUNNING, status update state:
TASK_RUNNING)
3: I1111 06:54:43.954803 17264 sched.cpp:1029] Scheduler::statusUpdate took 110672ns
3: I1111 06:54:43.955158 17271 master.cpp:5792] Processing ACKNOWLEDGE call cda3c057-1ba3-47a7-8d61-4a8cef1c2171
for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 (default) at scheduler-6bf08b38-c4f3-4b39-829d-206f49592ab0@172.17.0.2:46580
on agent f087df97-96b4-4cc9-b99a-a36b74462017-S0
3: I1111 06:54:43.955282 17257 sched.cpp:2009] Asked to stop the driver
3: I1111 06:54:43.955390 17267 sched.cpp:1191] Stopping framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.955544 17263 status_update_manager.cpp:395] Received status update acknowledgement
(UUID: cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.955682 17261 master.cpp:8793] Processing TEARDOWN call for framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
(default) at scheduler-6bf08b38-c4f3-4b39-829d-206f49592ab0@172.17.0.2:46580
3: I1111 06:54:43.955724 17261 master.cpp:8805] Removing framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
(default) at scheduler-6bf08b38-c4f3-4b39-829d-206f49592ab0@172.17.0.2:46580
3: I1111 06:54:43.955821 17261 master.cpp:3332] Deactivating framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
(default) at scheduler-6bf08b38-c4f3-4b39-829d-206f49592ab0@172.17.0.2:46580
3: I1111 06:54:43.955840 17266 slave.cpp:3791] Status update manager successfully handled
status update acknowledgement (UUID: cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework
f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.955972 17269 hierarchical.cpp:412] Deactivated framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.956069 17261 master.cpp:9503] Updating the state of task 1 of framework
f087df97-96b4-4cc9-b99a-a36b74462017-0000 (latest state: TASK_KILLED, status update state:
TASK_KILLED)
3: I1111 06:54:43.956070 17259 slave.cpp:3267] Asked to shut down framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
by master@172.17.0.2:46580
3: I1111 06:54:43.956120 17259 slave.cpp:3292] Shutting down framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.956161 17259 slave.cpp:5855] Shutting down executor 'test-executor' of framework
f087df97-96b4-4cc9-b99a-a36b74462017-0000 at executor(115)@172.17.0.2:46580
3: I1111 06:54:43.956259 17258 exec.cpp:435] Executor asked to shutdown
3: I1111 06:54:43.956292 17258 exec.cpp:450] Executor::shutdown took 18445ns
3: I1111 06:54:43.956493 17271 slave.cpp:5120] Got exited event for executor(115)@172.17.0.2:46580
3: I1111 06:54:43.956903 17261 master.cpp:9597] Removing 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"}]
of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 on agent f087df97-96b4-4cc9-b99a-a36b74462017-S0
at slave(299)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:43.957639 17261 master.cpp:9626] Removing executor 'test-executor' with resources
[] of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 on agent f087df97-96b4-4cc9-b99a-a36b74462017-S0
at slave(299)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:43.957675 17260 slave.cpp:5520] Executor 'test-executor' of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
exited with status 0
3: I1111 06:54:43.957757 17260 slave.cpp:5624] Cleaning up executor 'test-executor' of framework
f087df97-96b4-4cc9-b99a-a36b74462017-0000 at executor(115)@172.17.0.2:46580
3: I1111 06:54:43.957852 17265 hierarchical.cpp:1125] Recovered cpus(allocated: *):2; mem(allocated:
*):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024;
disk:1024; ports:[31000-32000], allocated: {}) on agent f087df97-96b4-4cc9-b99a-a36b74462017-S0
from framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.958060 17264 gc.cpp:90] Scheduling '/tmp/MasterAuthorizationTest_AuthorizedTask_FnQEhi/slaves/f087df97-96b4-4cc9-b99a-a36b74462017-S0/frameworks/f087df97-96b4-4cc9-b99a-a36b74462017-0000/executors/test-executor/runs/4525ebe0-68ad-40bc-b25a-99fde9fdb05c'
for gc 6.99998891267259days in the future
3: I1111 06:54:43.958277 17260 slave.cpp:5731] Cleaning up framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.958276 17263 gc.cpp:90] Scheduling '/tmp/MasterAuthorizationTest_AuthorizedTask_FnQEhi/slaves/f087df97-96b4-4cc9-b99a-a36b74462017-S0/frameworks/f087df97-96b4-4cc9-b99a-a36b74462017-0000/executors/test-executor'
for gc 6.99998891001185days in the future
3: I1111 06:54:43.958384 17269 status_update_manager.cpp:285] Closing status update streams
for framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.958428 17269 status_update_manager.cpp:531] Cleaning up status update stream
for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.958480 17259 hierarchical.cpp:355] Removed framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.958544 17263 gc.cpp:90] Scheduling '/tmp/MasterAuthorizationTest_AuthorizedTask_FnQEhi/slaves/f087df97-96b4-4cc9-b99a-a36b74462017-S0/frameworks/f087df97-96b4-4cc9-b99a-a36b74462017-0000'
for gc 6.99998890715259days in the future
3: W1111 06:54:43.958709 17261 master.cpp:7454] Ignoring unknown exited executor 'test-executor'
of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 on agent f087df97-96b4-4cc9-b99a-a36b74462017-S0
at slave(299)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:43.959002 17265 slave.cpp:883] Agent terminating
3: I1111 06:54:43.959193 17264 master.cpp:1309] Agent f087df97-96b4-4cc9-b99a-a36b74462017-S0
at slave(299)@172.17.0.2:46580 (2782842d33d5) disconnected
3: I1111 06:54:43.959219 17264 master.cpp:3369] Disconnecting agent f087df97-96b4-4cc9-b99a-a36b74462017-S0
at slave(299)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:43.959271 17264 master.cpp:3388] Deactivating agent f087df97-96b4-4cc9-b99a-a36b74462017-S0
at slave(299)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:43.959352 17267 hierarchical.cpp:690] Agent f087df97-96b4-4cc9-b99a-a36b74462017-S0
deactivated
3: I1111 06:54:43.963544 17257 master.cpp:1151] Master terminating
3: I1111 06:54:43.964382 17273 hierarchical.cpp:626] Removed agent f087df97-96b4-4cc9-b99a-a36b74462017-S0
3: [       OK ] MasterAuthorizationTest.AuthorizedTask (74 ms)
3: [ RUN      ] MasterAuthorizationTest.UnauthorizedTask
3: I1111 06:54:43.973251 17257 cluster.cpp:162] Creating default 'local' authorizer
3: I1111 06:54:43.976135 17267 master.cpp:448] Master 2f7f580a-832b-4e20-9015-63576543d149
(2782842d33d5) started on 172.17.0.2:46580
3: I1111 06:54:43.976161 17267 master.cpp:450] Flags at startup: --acls="run_tasks {
3:   principals {
3:     type: NONE
3:   }
3:   users {
3:     values: "foo"
3:   }
3: }
3: " --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/NihwMS/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/NihwMS/master"
--zk_session_timeout="10secs"
3: I1111 06:54:43.976595 17267 master.cpp:499] Master only allowing authenticated frameworks
to register
3: I1111 06:54:43.976605 17267 master.cpp:505] Master only allowing authenticated agents to
register
3: I1111 06:54:43.976611 17267 master.cpp:511] Master only allowing authenticated HTTP frameworks
to register
3: I1111 06:54:43.976617 17267 credentials.hpp:37] Loading credentials for authentication
from '/tmp/NihwMS/credentials'
3: I1111 06:54:43.976933 17267 master.cpp:555] Using default 'crammd5' authenticator
3: I1111 06:54:43.977088 17267 http.cpp:1045] Creating default 'basic' HTTP authenticator
for realm 'mesos-master-readonly'
3: I1111 06:54:43.977284 17267 http.cpp:1045] Creating default 'basic' HTTP authenticator
for realm 'mesos-master-readwrite'
3: I1111 06:54:43.977460 17267 http.cpp:1045] Creating default 'basic' HTTP authenticator
for realm 'mesos-master-scheduler'
3: I1111 06:54:43.977596 17267 master.cpp:634] Authorization enabled
3: I1111 06:54:43.977825 17258 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1111 06:54:43.977869 17262 whitelist_watcher.cpp:77] No whitelist given
3: I1111 06:54:43.980875 17269 master.cpp:2213] Elected as the leading master!
3: I1111 06:54:43.980906 17269 master.cpp:1693] Recovering from registrar
3: I1111 06:54:43.981099 17272 registrar.cpp:347] Recovering registrar
3: I1111 06:54:43.981734 17272 registrar.cpp:391] Successfully fetched the registry (0B) in
591872ns
3: I1111 06:54:43.981842 17272 registrar.cpp:495] Applied 1 operations in 28515ns; attempting
to update the registry
3: I1111 06:54:43.982393 17272 registrar.cpp:552] Successfully updated the registry in 495872ns
3: I1111 06:54:43.982520 17272 registrar.cpp:424] Successfully recovered registrar
3: I1111 06:54:43.982954 17258 master.cpp:1806] Recovered 0 agents from the registry (129B);
allowing 10mins for agents to re-register
3: I1111 06:54:43.983021 17260 hierarchical.cpp:209] Skipping recovery of hierarchical allocator:
nothing to recover
3: W1111 06:54:43.988366 17257 process.cpp:3178] Attempted to spawn already running process
files@172.17.0.2:46580
3: I1111 06:54:43.988705 17257 cluster.cpp:448] Creating default 'local' authorizer
3: I1111 06:54:43.991094 17272 slave.cpp:262] Mesos agent started on (300)@172.17.0.2:46580
3: I1111 06:54:43.991116 17272 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"
--appc_store_dir="/tmp/MasterAuthorizationTest_UnauthorizedTask_ZtEjjb/store/appc" --authenticate_http_readonly="true"
--authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs"
--authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false"
--cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs"
--containerizers="mesos" --credential="/tmp/MasterAuthorizationTest_UnauthorizedTask_ZtEjjb/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/MasterAuthorizationTest_UnauthorizedTask_ZtEjjb/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume"
--enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs"
--executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/MasterAuthorizationTest_UnauthorizedTask_ZtEjjb/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/MasterAuthorizationTest_UnauthorizedTask_ZtEjjb/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/MasterAuthorizationTest_UnauthorizedTask_ZtEjjb" --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/MasterAuthorizationTest_UnauthorizedTask_MElU21" --zk_session_timeout="10secs"
3: I1111 06:54:43.991639 17272 credentials.hpp:86] Loading credential for authentication from
'/tmp/MasterAuthorizationTest_UnauthorizedTask_ZtEjjb/credential'
3: W1111 06:54:43.991662 17257 process.cpp:3178] Attempted to spawn already running process
version@172.17.0.2:46580
3: I1111 06:54:43.991834 17272 slave.cpp:295] Agent using credential for: test-principal
3: I1111 06:54:43.991853 17272 credentials.hpp:37] Loading credentials for authentication
from '/tmp/MasterAuthorizationTest_UnauthorizedTask_ZtEjjb/http_credentials'
3: I1111 06:54:43.992193 17272 http.cpp:1045] Creating default 'basic' HTTP authenticator
for realm 'mesos-agent-readonly'
3: I1111 06:54:43.992338 17272 http.cpp:1045] Creating default 'basic' HTTP authenticator
for realm 'mesos-agent-readwrite'
3: I1111 06:54:43.992594 17257 sched.cpp:232] Version: 1.5.0
3: I1111 06:54:43.993161 17261 sched.cpp:336] New master detected at master@172.17.0.2:46580
3: I1111 06:54:43.993278 17261 sched.cpp:396] Authenticating with master master@172.17.0.2:46580
3: I1111 06:54:43.993299 17261 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1111 06:54:43.993563 17262 authenticatee.cpp:121] Creating new client SASL connection
3: I1111 06:54:43.993873 17260 master.cpp:8286] Authenticating scheduler-4ee42587-8bd8-4f22-ab48-ae8afc1fd796@172.17.0.2:46580
3: I1111 06:54:43.994036 17268 authenticator.cpp:414] Starting authentication session for
crammd5-authenticatee(628)@172.17.0.2:46580
3: I1111 06:54:43.993953 17272 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: I1111 06:54:43.994233 17272 slave.cpp:601] Agent attributes: [  ]
3: I1111 06:54:43.994246 17272 slave.cpp:610] Agent hostname: 2782842d33d5
3: I1111 06:54:43.994402 17269 authenticator.cpp:98] Creating new server SASL connection
3: I1111 06:54:43.994428 17267 status_update_manager.cpp:177] Pausing sending status updates
3: I1111 06:54:43.994654 17271 authenticatee.cpp:213] Received SASL authentication mechanisms:
CRAM-MD5
3: I1111 06:54:43.994683 17271 authenticatee.cpp:239] Attempting to authenticate with mechanism
'CRAM-MD5'
3: I1111 06:54:43.994813 17273 authenticator.cpp:204] Received SASL authentication start
3: I1111 06:54:43.994879 17273 authenticator.cpp:326] Authentication requires more steps
3: I1111 06:54:43.995036 17266 authenticatee.cpp:259] Received SASL authentication step
3: I1111 06:54:43.995183 17266 authenticator.cpp:232] Received SASL authentication step
3: I1111 06:54:43.995213 17266 auxprop.cpp:109] Request to lookup properties for user: 'test-principal'
realm: '2782842d33d5' server FQDN: '2782842d33d5' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1111 06:54:43.995224 17266 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1111 06:54:43.995255 17266 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1111 06:54:43.995275 17266 auxprop.cpp:109] Request to lookup properties for user: 'test-principal'
realm: '2782842d33d5' server FQDN: '2782842d33d5' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1111 06:54:43.995287 17266 auxprop.cpp:131] Skipping auxiliary property '*userPassword'
since SASL_AUXPROP_AUTHZID == true
3: I1111 06:54:43.995296 17266 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5'
since SASL_AUXPROP_AUTHZID == true
3: I1111 06:54:43.995311 17266 authenticator.cpp:318] Authentication success
3: I1111 06:54:43.995404 17264 authenticatee.cpp:299] Authentication success
3: I1111 06:54:43.995471 17265 master.cpp:8316] Successfully authenticated principal 'test-principal'
at scheduler-4ee42587-8bd8-4f22-ab48-ae8afc1fd796@172.17.0.2:46580
3: I1111 06:54:43.995527 17266 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(628)@172.17.0.2:46580
3: I1111 06:54:43.995712 17261 sched.cpp:502] Successfully authenticated with master master@172.17.0.2:46580
3: I1111 06:54:43.995734 17261 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.2:46580
3: I1111 06:54:43.995849 17261 sched.cpp:857] Will retry registration in 1.571954047secs if
necessary
3: I1111 06:54:43.996047 17267 master.cpp:2962] Received SUBSCRIBE call for framework 'default'
at scheduler-4ee42587-8bd8-4f22-ab48-ae8afc1fd796@172.17.0.2:46580
3: I1111 06:54:43.996129 17267 master.cpp:2278] Authorizing framework principal 'test-principal'
to receive offers for roles '{ * }'
3: I1111 06:54:43.996428 17273 state.cpp:64] Recovering state from '/tmp/MasterAuthorizationTest_UnauthorizedTask_MElU21/meta'
3: I1111 06:54:43.996857 17273 master.cpp:3042] Subscribing framework default with checkpointing
disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1111 06:54:43.996896 17259 status_update_manager.cpp:203] Recovering status update manager
3: I1111 06:54:43.997335 17262 slave.cpp:6422] Finished recovery
3: I1111 06:54:43.997484 17273 sched.cpp:751] Framework registered with 2f7f580a-832b-4e20-9015-63576543d149-0000
3: I1111 06:54:43.997534 17273 sched.cpp:765] Scheduler::registered took 22365ns
3: I1111 06:54:43.997668 17266 hierarchical.cpp:303] Added framework 2f7f580a-832b-4e20-9015-63576543d149-0000
3: I1111 06:54:43.997913 17266 hierarchical.cpp:1450] Performed allocation for 0 agents in
98576ns
3: I1111 06:54:43.998292 17271 slave.cpp:1007] New master detected at master@172.17.0.2:46580
3: I1111 06:54:43.998329 17264 status_update_manager.cpp:177] Pausing sending status updates
3: I1111 06:54:43.998397 17271 slave.cpp:1042] Detecting new master
3: I1111 06:54:44.004760 17270 slave.cpp:1069] Authenticating with master master@172.17.0.2:46580
3: I1111 06:54:44.004832 17270 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1111 06:54:44.005084 17258 authenticatee.cpp:121] Creating new client SASL connection
3: I1111 06:54:44.005373 17260 master.cpp:8286] Authenticating slave(300)@172.17.0.2:46580
3: I1111 06:54:44.005491 17259 authenticator.cpp:414] Starting authentication session for
crammd5-authenticatee(629)@172.17.0.2:46580
3: I1111 06:54:44.005751 17268 authenticator.cpp:98] Creating new server SASL connection
3: I1111 06:54:44.006021 17267 authenticatee.cpp:213] Received SASL authentication mechanisms:
CRAM-MD5
3: I1111 06:54:44.006050 17267 authenticatee.cpp:239] Attempting to authenticate with mechanism
'CRAM-MD5'
3: I1111 06:54:44.006167 17261 authenticator.cpp:204] Received SASL authentication start
3: I1111 06:54:44.006222 17261 authenticator.cpp:326] Authentication requires more steps
3: I1111 06:54:44.006323 17261 authenticatee.cpp:259] Received SASL authentication step
3: I1111 06:54:44.006467 17269 authenticator.cpp:232] Received SASL authentication step
3: I1111 06:54:44.006498 17269 auxprop.cpp:109] Request to lookup properties for user: 'test-principal'
realm: '2782842d33d5' server FQDN: '2782842d33d5' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1111 06:54:44.006508 17269 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1111 06:54:44.006536 17269 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1111 06:54:44.006553 17269 auxprop.cpp:109] Request to lookup properties for user: 'test-principal'
realm: '2782842d33d5' server FQDN: '2782842d33d5' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1111 06:54:44.006564 17269 auxprop.cpp:131] Skipping auxiliary property '*userPassword'
since SASL_AUXPROP_AUTHZID == true
3: I1111 06:54:44.006572 17269 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5'
since SASL_AUXPROP_AUTHZID == true
3: I1111 06:54:44.006585 17269 authenticator.cpp:318] Authentication success
3: I1111 06:54:44.006680 17266 authenticatee.cpp:299] Authentication success
3: I1111 06:54:44.006731 17262 master.cpp:8316] Successfully authenticated principal 'test-principal'
at slave(300)@172.17.0.2:46580
3: I1111 06:54:44.006762 17263 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(629)@172.17.0.2:46580
3: I1111 06:54:44.007067 17272 slave.cpp:1161] Successfully authenticated with master master@172.17.0.2:46580
3: I1111 06:54:44.007295 17272 slave.cpp:1682] Will retry registration in 12.984422ms if necessary
3: I1111 06:54:44.007504 17270 master.cpp:6033] Received register agent message from slave(300)@172.17.0.2:46580
(2782842d33d5)
3: I1111 06:54:44.007642 17270 master.cpp:3871] Authorizing agent with principal 'test-principal'
3: I1111 06:54:44.008059 17260 master.cpp:6093] Authorized registration of agent at slave(300)@172.17.0.2:46580
(2782842d33d5)
3: I1111 06:54:44.008169 17260 master.cpp:6186] Registering agent at slave(300)@172.17.0.2:46580
(2782842d33d5) with id 2f7f580a-832b-4e20-9015-63576543d149-S0
3: I1111 06:54:44.008705 17259 registrar.cpp:495] Applied 1 operations in 64603ns; attempting
to update the registry
3: I1111 06:54:44.009331 17259 registrar.cpp:552] Successfully updated the registry in 561152ns
3: I1111 06:54:44.009577 17269 master.cpp:6233] Admitted agent 2f7f580a-832b-4e20-9015-63576543d149-S0
at slave(300)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:44.010349 17262 slave.cpp:1207] Registered with master master@172.17.0.2:46580;
given agent ID 2f7f580a-832b-4e20-9015-63576543d149-S0
3: I1111 06:54:44.010496 17265 status_update_manager.cpp:184] Resuming sending status updates
3: I1111 06:54:44.010257 17269 master.cpp:6264] Registered agent 2f7f580a-832b-4e20-9015-63576543d149-S0
at slave(300)@172.17.0.2:46580 (2782842d33d5) 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: I1111 06:54:44.010663 17264 hierarchical.cpp:593] Added agent 2f7f580a-832b-4e20-9015-63576543d149-S0
(2782842d33d5) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
3: I1111 06:54:44.010701 17262 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/MasterAuthorizationTest_UnauthorizedTask_MElU21/meta/slaves/2f7f580a-832b-4e20-9015-63576543d149-S0/slave.info'
3: I1111 06:54:44.011144 17262 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: I1111 06:54:44.011348 17262 master.cpp:7065] Received update of agent 2f7f580a-832b-4e20-9015-63576543d149-S0
at slave(300)@172.17.0.2:46580 (2782842d33d5) with total oversubscribed resources {}
3: I1111 06:54:44.011538 17262 master.cpp:7083] Ignoring update on agent 2f7f580a-832b-4e20-9015-63576543d149-S0
at slave(300)@172.17.0.2:46580 (2782842d33d5) as it reports no changes
3: I1111 06:54:44.012274 17264 hierarchical.cpp:1450] Performed allocation for 1 agents in
1.392507ms
3: I1111 06:54:44.012774 17272 master.cpp:8116] Sending 1 offers to framework 2f7f580a-832b-4e20-9015-63576543d149-0000
(default) at scheduler-4ee42587-8bd8-4f22-ab48-ae8afc1fd796@172.17.0.2:46580
3: I1111 06:54:44.013392 17270 sched.cpp:921] Scheduler::resourceOffers took 124522ns
3: I1111 06:54:44.015431 17266 master.cpp:10016] Removing offer 2f7f580a-832b-4e20-9015-63576543d149-O0
3: I1111 06:54:44.015609 17266 master.cpp:4229] Processing ACCEPT call for offers: [ 2f7f580a-832b-4e20-9015-63576543d149-O0
] on agent 2f7f580a-832b-4e20-9015-63576543d149-S0 at slave(300)@172.17.0.2:46580 (2782842d33d5)
for framework 2f7f580a-832b-4e20-9015-63576543d149-0000 (default) at scheduler-4ee42587-8bd8-4f22-ab48-ae8afc1fd796@172.17.0.2:46580
3: I1111 06:54:44.015755 17266 master.cpp:3598] Authorizing framework principal 'test-principal'
to launch task 1
3: I1111 06:54:44.017117 17269 master.cpp:7305] Sending status update TASK_ERROR for task
1 of framework 2f7f580a-832b-4e20-9015-63576543d149-0000 'Not authorized to launch as user
'foo''
3: I1111 06:54:44.017491 17264 sched.cpp:1029] Scheduler::statusUpdate took 64801ns
3: I1111 06:54:44.018162 17268 master.cpp:7704] Performing implicit task state reconciliation
for framework 2f7f580a-832b-4e20-9015-63576543d149-0000 (default) at scheduler-4ee42587-8bd8-4f22-ab48-ae8afc1fd796@172.17.0.2:46580
3: I1111 06:54:44.018339 17272 hierarchical.cpp:1125] Recovered cpus(allocated: *):2; mem(allocated:
*):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024;
disk:1024; ports:[31000-32000], allocated: {}) on agent 2f7f580a-832b-4e20-9015-63576543d149-S0
from framework 2f7f580a-832b-4e20-9015-63576543d149-0000
3: I1111 06:54:44.018420 17272 hierarchical.cpp:1171] Framework 2f7f580a-832b-4e20-9015-63576543d149-0000
filtered agent 2f7f580a-832b-4e20-9015-63576543d149-S0 for 5secs
3: I1111 06:54:44.018632 17257 sched.cpp:2009] Asked to stop the driver
3: I1111 06:54:44.018735 17259 sched.cpp:1191] Stopping framework 2f7f580a-832b-4e20-9015-63576543d149-0000
3: I1111 06:54:44.019057 17271 master.cpp:8793] Processing TEARDOWN call for framework 2f7f580a-832b-4e20-9015-63576543d149-0000
(default) at scheduler-4ee42587-8bd8-4f22-ab48-ae8afc1fd796@172.17.0.2:46580
3: I1111 06:54:44.019095 17271 master.cpp:8805] Removing framework 2f7f580a-832b-4e20-9015-63576543d149-0000
(default) at scheduler-4ee42587-8bd8-4f22-ab48-ae8afc1fd796@172.17.0.2:46580
3: I1111 06:54:44.019111 17271 master.cpp:3332] Deactivating framework 2f7f580a-832b-4e20-9015-63576543d149-0000
(default) at scheduler-4ee42587-8bd8-4f22-ab48-ae8afc1fd796@172.17.0.2:46580
3: I1111 06:54:44.019245 17263 hierarchical.cpp:412] Deactivated framework 2f7f580a-832b-4e20-9015-63576543d149-0000
3: I1111 06:54:44.019358 17263 slave.cpp:3267] Asked to shut down framework 2f7f580a-832b-4e20-9015-63576543d149-0000
by master@172.17.0.2:46580
3: I1111 06:54:44.019395 17263 slave.cpp:3282] Cannot shut down unknown framework 2f7f580a-832b-4e20-9015-63576543d149-0000
3: I1111 06:54:44.019805 17267 hierarchical.cpp:355] Removed framework 2f7f580a-832b-4e20-9015-63576543d149-0000
3: I1111 06:54:44.020354 17257 slave.cpp:883] Agent terminating
3: I1111 06:54:44.020539 17262 master.cpp:1309] Agent 2f7f580a-832b-4e20-9015-63576543d149-S0
at slave(300)@172.17.0.2:46580 (2782842d33d5) disconnected
3: I1111 06:54:44.020570 17262 master.cpp:3369] Disconnecting agent 2f7f580a-832b-4e20-9015-63576543d149-S0
at slave(300)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:44.020643 17262 master.cpp:3388] Deactivating agent 2f7f580a-832b-4e20-9015-63576543d149-S0
at slave(300)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:44.020776 17260 hierarchical.cpp:690] Agent 2f7f580a-832b-4e20-9015-63576543d149-S0
deactivated
3: I1111 06:54:44.024834 17257 master.cpp:1151] Master terminating
3: I1111 06:54:44.025576 17268 hierarchical.cpp:626] Removed agent 2f7f580a-832b-4e20-9015-63576543d149-S0
3: [       OK ] MasterAuthorizationTest.UnauthorizedTask (59 ms)
3: [ RUN      ] MasterAuthorizationTest.UnauthorizedTaskGroup
3: I1111 06:54:44.032232 17257 cluster.cpp:162] Creating default 'local' authorizer
3: I1111 06:54:44.035271 17259 master.cpp:448] Master fef770b0-29b9-4f39-95bd-71c650445e2e
(2782842d33d5) started on 172.17.0.2:46580
3: I1111 06:54:44.035295 17259 master.cpp:450] Flags at startup: --acls="run_tasks {
3:   principals {
3:     type: NONE
3:   }
3:   users {
3:     values: "foo"
3:   }
3: }
3: " --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/MiBBjD/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/MiBBjD/master"
--zk_session_timeout="10secs"
3: I1111 06:54:44.035706 17259 master.cpp:499] Master only allowing authenticated frameworks
to register
3: I1111 06:54:44.035715 17259 master.cpp:505] Master only allowing authenticated agents to
register
3: I1111 06:54:44.035722 17259 master.cpp:511] Master only allowing authenticated HTTP frameworks
to register
3: I1111 06:54:44.035727 17259 credentials.hpp:37] Loading credentials for authentication
from '/tmp/MiBBjD/credentials'
3: I1111 06:54:44.036115 17259 master.cpp:555] Using default 'crammd5' authenticator
3: I1111 06:54:44.036270 17259 http.cpp:1045] Creating default 'basic' HTTP authenticator
for realm 'mesos-master-readonly'
3: I1111 06:54:44.036434 17259 http.cpp:1045] Creating default 'basic' HTTP authenticator
for realm 'mesos-master-readwrite'
3: I1111 06:54:44.036598 17259 http.cpp:1045] Creating default 'basic' HTTP authenticator
for realm 'mesos-master-scheduler'
3: I1111 06:54:44.036753 17259 master.cpp:634] Authorization enabled
3: I1111 06:54:44.036933 17271 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1111 06:54:44.036940 17264 whitelist_watcher.cpp:77] No whitelist given
3: I1111 06:54:44.039788 17259 master.cpp:2213] Elected as the leading master!
3: I1111 06:54:44.039820 17259 master.cpp:1693] Recovering from registrar
3: I1111 06:54:44.040092 17266 registrar.cpp:347] Recovering registrar
3: I1111 06:54:44.040659 17266 registrar.cpp:391] Successfully fetched the registry (0B) in
526848ns
3: I1111 06:54:44.040766 17266 registrar.cpp:495] Applied 1 operations in 26952ns; attempting
to update the registry
3: I1111 06:54:44.041306 17266 registrar.cpp:552] Successfully updated the registry in 486144ns
3: I1111 06:54:44.041434 17266 registrar.cpp:424] Successfully recovered registrar
3: I1111 06:54:44.041854 17271 master.cpp:1806] Recovered 0 agents from the registry (129B);
allowing 10mins for agents to re-register
3: I1111 06:54:44.041905 17270 hierarchical.cpp:209] Skipping recovery of hierarchical allocator:
nothing to recover
3: W1111 06:54:44.047060 17257 process.cpp:3178] Attempted to spawn already running process
files@172.17.0.2:46580
3: I1111 06:54:44.048188 17257 containerizer.cpp:301] Using isolation { environment_secret,
posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1111 06:54:44.048873 17257 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend
requires root privileges
3: W1111 06:54:44.049003 17257 backend.cpp:76] Failed to create 'bind' backend: BindBackend
requires root privileges
3: I1111 06:54:44.049052 17257 provisioner.cpp:255] Using default backend 'copy'
write /dev/stdout: resource temporarily unavailable
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user yujie.jay@gmail.com


Mime
View raw message