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/28 17:03:47 UTC
Build failed in Jenkins: Mesos-Buildbot » cmake,clang,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4506
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4506/display/redirect?page=changes>
Changes:
[jpeach] Added a space to an error string.
------------------------------------------
[...truncated 13.48 MB...]
3: I1128 17:03:38.280529 18360 hierarchical.cpp:306] Added framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000
3: I1128 17:03:38.280567 18360 hierarchical.cpp:419] Deactivated framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000
3: I1128 17:03:38.280575 18371 sched.cpp:330] Scheduler::disconnected took 29153ns
3: I1128 17:03:38.280591 18371 sched.cpp:336] New master detected at master@172.17.0.4:46683
3: I1128 17:03:38.280673 18371 sched.cpp:396] Authenticating with master master@172.17.0.4:46683
3: I1128 17:03:38.280701 18371 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1128 17:03:38.280992 18362 authenticatee.cpp:121] Creating new client SASL connection
3: I1128 17:03:38.281266 18362 master.cpp:8312] Authenticating scheduler-1d424f1a-1cc6-4e0a-959f-c551a1898a19@172.17.0.4:46683
3: I1128 17:03:38.281361 18370 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(577)@172.17.0.4:46683
3: I1128 17:03:38.281599 18365 authenticator.cpp:98] Creating new server SASL connection
3: I1128 17:03:38.281821 18354 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1128 17:03:38.281842 18354 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1128 17:03:38.281962 18352 authenticator.cpp:204] Received SASL authentication start
3: I1128 17:03:38.282018 18352 authenticator.cpp:326] Authentication requires more steps
3: I1128 17:03:38.282125 18367 authenticatee.cpp:259] Received SASL authentication step
3: I1128 17:03:38.282256 18359 authenticator.cpp:232] Received SASL authentication step
3: I1128 17:03:38.282294 18359 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '78dd34898e51' server FQDN: '78dd34898e51' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1128 17:03:38.282301 18359 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1128 17:03:38.282323 18359 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1128 17:03:38.282336 18359 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '78dd34898e51' server FQDN: '78dd34898e51' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1128 17:03:38.282347 18359 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1128 17:03:38.282352 18359 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1128 17:03:38.282363 18359 authenticator.cpp:318] Authentication success
3: I1128 17:03:38.282423 18355 authenticatee.cpp:299] Authentication success
3: I1128 17:03:38.282476 18369 master.cpp:8342] Successfully authenticated principal 'test-principal' at scheduler-1d424f1a-1cc6-4e0a-959f-c551a1898a19@172.17.0.4:46683
3: I1128 17:03:38.282508 18373 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(577)@172.17.0.4:46683
3: I1128 17:03:38.282696 18358 sched.cpp:502] Successfully authenticated with master master@172.17.0.4:46683
3: I1128 17:03:38.282713 18358 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.4:46683
3: I1128 17:03:38.282815 18358 sched.cpp:857] Will retry registration in 464.018713ms if necessary
3: I1128 17:03:38.282982 18363 master.cpp:2963] Received SUBSCRIBE call for framework 'default' at scheduler-1d424f1a-1cc6-4e0a-959f-c551a1898a19@172.17.0.4:46683
3: I1128 17:03:38.283002 18363 master.cpp:2280] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
3: I1128 17:03:38.283419 18351 master.cpp:3043] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1128 17:03:38.283473 18351 master.cpp:6994] Updating info for framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000
3: I1128 17:03:38.283757 18361 hierarchical.cpp:385] Activated framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000
3: I1128 17:03:38.283906 18356 sched.cpp:751] Framework registered with c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000
3: I1128 17:03:38.283946 18356 sched.cpp:765] Scheduler::registered took 23146ns
3: I1128 17:03:38.283993 18360 slave.cpp:3441] Updating info for framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000 with pid updated to scheduler-1d424f1a-1cc6-4e0a-959f-c551a1898a19@172.17.0.4:46683
3: I1128 17:03:38.284104 18371 task_status_update_manager.cpp:188] Resuming sending task status updates
3: I1128 17:03:38.284811 18361 hierarchical.cpp:1457] Performed allocation for 1 agents in 946652ns
3: I1128 17:03:38.285238 18357 master.cpp:8142] Sending 1 offers to framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000 (default) at scheduler-1d424f1a-1cc6-4e0a-959f-c551a1898a19@172.17.0.4:46683
3: I1128 17:03:38.285764 18374 sched.cpp:921] Scheduler::resourceOffers took 127474ns
3: I1128 17:03:38.286088 18350 sched.cpp:2009] Asked to stop the driver
3: I1128 17:03:38.286170 18352 sched.cpp:1191] Stopping framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000
3: I1128 17:03:38.286379 18367 master.cpp:8819] Processing TEARDOWN call for framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000 (default) at scheduler-1d424f1a-1cc6-4e0a-959f-c551a1898a19@172.17.0.4:46683
3: I1128 17:03:38.286404 18367 master.cpp:8831] Removing framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000 (default) at scheduler-1d424f1a-1cc6-4e0a-959f-c551a1898a19@172.17.0.4:46683
3: I1128 17:03:38.286415 18367 master.cpp:3333] Deactivating framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000 (default) at scheduler-1d424f1a-1cc6-4e0a-959f-c551a1898a19@172.17.0.4:46683
3: I1128 17:03:38.286561 18369 hierarchical.cpp:419] Deactivated framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000
3: I1128 17:03:38.286953 18367 master.cpp:10063] Removing offer 54796f57-8938-491c-a058-aaf66d264c41-O0
3: I1128 17:03:38.287122 18367 master.cpp:9529] Updating the state of task 0 of framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
3: I1128 17:03:38.287191 18353 slave.cpp:3270] Asked to shut down framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000 by master@172.17.0.4:46683
3: I1128 17:03:38.287228 18353 slave.cpp:3295] Shutting down framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000
3: I1128 17:03:38.287263 18353 slave.cpp:5923] Shutting down executor 'default' of framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000 at executor(102)@172.17.0.4:46683
3: I1128 17:03:38.287354 18364 exec.cpp:435] Executor asked to shutdown
3: I1128 17:03:38.287384 18364 exec.cpp:450] Executor::shutdown took 19697ns
3: I1128 17:03:38.287400 18358 hierarchical.cpp:1132] Recovered cpus(allocated: *):1; mem(allocated: *):524; disk(allocated: *):367489; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:367489; ports:[31000-32000], allocated: cpus(allocated: *):1; mem(allocated: *):500) on agent c1be652f-284d-4267-96fc-b13ddf4e7ef0-S0 from framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000
3: I1128 17:03:38.287535 18364 slave.cpp:5179] Got exited event for executor(102)@172.17.0.4:46683
3: I1128 17:03:38.287539 18367 master.cpp:9629] Removing task 0 with resources cpus(allocated: *):1; mem(allocated: *):500 of framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000 on agent c1be652f-284d-4267-96fc-b13ddf4e7ef0-S0 at slave(278)@172.17.0.4:46683 (78dd34898e51)
3: I1128 17:03:38.287786 18367 master.cpp:9658] Removing executor 'default' with resources [] of framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000 on agent c1be652f-284d-4267-96fc-b13ddf4e7ef0-S0 at slave(278)@172.17.0.4:46683 (78dd34898e51)
3: I1128 17:03:38.287904 18358 hierarchical.cpp:1132] Recovered cpus(allocated: *):1; mem(allocated: *):500 (total: cpus:2; mem:1024; disk:367489; ports:[31000-32000], allocated: {}) on agent c1be652f-284d-4267-96fc-b13ddf4e7ef0-S0 from framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000
3: I1128 17:03:38.288188 18367 master.cpp:1153] Master terminating
3: I1128 17:03:38.288341 18361 hierarchical.cpp:358] Removed framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000
3: I1128 17:03:38.288748 18352 slave.cpp:5179] Got exited event for master@172.17.0.4:46683
3: W1128 17:03:38.288774 18352 slave.cpp:5184] Master disconnected! Waiting for a new master to be elected
3: I1128 17:03:38.288975 18361 hierarchical.cpp:633] Removed agent c1be652f-284d-4267-96fc-b13ddf4e7ef0-S0
3: I1128 17:03:38.292769 18358 slave.cpp:5588] Executor 'default' of framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000 exited with status 0
3: I1128 17:03:38.292902 18358 slave.cpp:5692] Cleaning up executor 'default' of framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000 at executor(102)@172.17.0.4:46683
3: I1128 17:03:38.293118 18367 gc.cpp:90] Scheduling '/tmp/MasterAllocatorTest_0_SlaveReregistersFirst_aNwcTo/slaves/c1be652f-284d-4267-96fc-b13ddf4e7ef0-S0/frameworks/c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000/executors/default/runs/3e6a871e-ca06-4606-8abd-fc354746da36' for gc 6.99999660866963days in the future
3: I1128 17:03:38.293259 18358 slave.cpp:5799] Cleaning up framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000
3: I1128 17:03:38.293412 18367 gc.cpp:90] Scheduling '/tmp/MasterAllocatorTest_0_SlaveReregistersFirst_aNwcTo/slaves/c1be652f-284d-4267-96fc-b13ddf4e7ef0-S0/frameworks/c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000/executors/default' for gc 6.99999660651556days in the future
3: I1128 17:03:38.293438 18366 task_status_update_manager.cpp:289] Closing task status update streams for framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000
3: I1128 17:03:38.293468 18358 slave.cpp:883] Agent terminating
3: I1128 17:03:38.293474 18366 task_status_update_manager.cpp:538] Cleaning up status update stream for task 0 of framework c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000
3: I1128 17:03:38.293545 18367 gc.cpp:90] Scheduling '/tmp/MasterAllocatorTest_0_SlaveReregistersFirst_aNwcTo/slaves/c1be652f-284d-4267-96fc-b13ddf4e7ef0-S0/frameworks/c1be652f-284d-4267-96fc-b13ddf4e7ef0-0000' for gc 6.99999660468741days in the future
3: [ OK ] MasterAllocatorTest/0.SlaveReregistersFirst (108 ms)
3: [ RUN ] MasterAllocatorTest/0.RebalancedForUpdatedWeights
3: I1128 17:03:38.301636 18350 cluster.cpp:162] Creating default 'local' authorizer
3: I1128 17:03:38.304460 18368 master.cpp:448] Master 3b3c9823-295a-4357-80fa-c07382f48ee0 (78dd34898e51) started on 172.17.0.4:46683
3: I1128 17:03:38.304493 18368 master.cpp:450] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/IgaKTA/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/IgaKTA/master" --zk_session_timeout="10secs"
3: I1128 17:03:38.304774 18368 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1128 17:03:38.304780 18368 master.cpp:505] Master only allowing authenticated agents to register
3: I1128 17:03:38.304783 18368 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1128 17:03:38.304788 18368 credentials.hpp:37] Loading credentials for authentication from '/tmp/IgaKTA/credentials'
3: I1128 17:03:38.305018 18368 master.cpp:555] Using default 'crammd5' authenticator
3: I1128 17:03:38.305155 18368 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1128 17:03:38.305297 18368 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1128 17:03:38.305430 18368 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1128 17:03:38.305557 18368 master.cpp:634] Authorization enabled
3: I1128 17:03:38.305724 18360 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1128 17:03:38.305778 18371 whitelist_watcher.cpp:77] No whitelist given
3: I1128 17:03:38.308091 18355 master.cpp:2215] Elected as the leading master!
3: I1128 17:03:38.308115 18355 master.cpp:1695] Recovering from registrar
3: I1128 17:03:38.308244 18359 registrar.cpp:347] Recovering registrar
3: I1128 17:03:38.308720 18359 registrar.cpp:391] Successfully fetched the registry (0B) in 0ns
3: I1128 17:03:38.308804 18359 registrar.cpp:495] Applied 1 operations in 28669ns; attempting to update the registry
3: I1128 17:03:38.309224 18359 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1128 17:03:38.309340 18359 registrar.cpp:424] Successfully recovered registrar
3: I1128 17:03:38.309691 18358 master.cpp:1808] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1128 17:03:38.309733 18367 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: W1128 17:03:38.314527 18350 process.cpp:2756] Attempted to spawn already running process files@172.17.0.4:46683
3: I1128 17:03:38.315522 18350 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1128 17:03:38.316023 18350 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1128 17:03:38.316154 18350 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1128 17:03:38.316190 18350 provisioner.cpp:259] Using default backend 'copy'
3: I1128 17:03:38.318271 18350 cluster.cpp:448] Creating default 'local' authorizer
3: I1128 17:03:38.320480 18367 slave.cpp:262] Mesos agent started on (279)@172.17.0.4:46683
3: I1128 17:03:38.320515 18367 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_WzWmgH/store/appc" --authenticate_http_executors="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_WzWmgH/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_WzWmgH/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_secret_key="/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_WzWmgH/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_WzWmgH/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_WzWmgH/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:2; mem:1024; disk:4096; ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_WzWmgH" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_eF524D" --zk_session_timeout="10secs"
3: I1128 17:03:38.320940 18367 credentials.hpp:86] Loading credential for authentication from '/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_WzWmgH/credential'
3: I1128 17:03:38.321120 18367 slave.cpp:295] Agent using credential for: test-principal
3: I1128 17:03:38.321143 18367 credentials.hpp:37] Loading credentials for authentication from '/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_WzWmgH/http_credentials'
3: I1128 17:03:38.321408 18363 hierarchical.cpp:1457] Performed allocation for 0 agents in 58464ns
3: I1128 17:03:38.321441 18367 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1128 17:03:38.321597 18367 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1128 17:03:38.321856 18367 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1128 17:03:38.321967 18367 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1128 17:03:38.322201 18367 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1128 17:03:38.322314 18367 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1128 17:03:38.323746 18367 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":4096.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1128 17:03:38.323963 18367 slave.cpp:601] Agent attributes: [ ]
3: I1128 17:03:38.323973 18367 slave.cpp:610] Agent hostname: 78dd34898e51
3: I1128 17:03:38.324110 18373 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1128 17:03:38.325683 18357 state.cpp:64] Recovering state from '/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_eF524D/meta'
3: I1128 17:03:38.325978 18357 task_status_update_manager.cpp:207] Recovering task status update manager
3: I1128 17:03:38.326174 18362 containerizer.cpp:668] Recovering containerizer
3: I1128 17:03:38.327491 18365 provisioner.cpp:455] Provisioner recovery complete
3: I1128 17:03:38.327811 18373 slave.cpp:6493] Finished recovery
3: I1128 17:03:38.328434 18358 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1128 17:03:38.328472 18353 slave.cpp:1007] New master detected at master@172.17.0.4:46683
3: I1128 17:03:38.328541 18353 slave.cpp:1042] Detecting new master
3: I1128 17:03:38.328806 18356 slave.cpp:1069] Authenticating with master master@172.17.0.4:46683
3: I1128 17:03:38.328900 18356 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1128 17:03:38.329146 18359 authenticatee.cpp:121] Creating new client SASL connection
3: I1128 17:03:38.329408 18357 master.cpp:8312] Authenticating slave(279)@172.17.0.4:46683
3: I1128 17:03:38.329516 18364 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(578)@172.17.0.4:46683
3: I1128 17:03:38.329767 18366 authenticator.cpp:98] Creating new server SASL connection
3: I1128 17:03:38.330027 18351 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1128 17:03:38.330054 18351 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1128 17:03:38.330183 18361 authenticator.cpp:204] Received SASL authentication start
3: I1128 17:03:38.330245 18361 authenticator.cpp:326] Authentication requires more steps
3: I1128 17:03:38.330361 18368 authenticatee.cpp:259] Received SASL authentication step
3: I1128 17:03:38.330476 18368 authenticator.cpp:232] Received SASL authentication step
3: I1128 17:03:38.330510 18368 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '78dd34898e51' server FQDN: '78dd34898e51' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1128 17:03:38.330521 18368 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1128 17:03:38.330554 18368 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1128 17:03:38.330571 18368 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '78dd34898e51' server FQDN: '78dd34898e51' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1128 17:03:38.330580 18368 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1128 17:03:38.330585 18368 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1128 17:03:38.330597 18368 authenticator.cpp:318] Authentication success
3: I1128 17:03:38.330669 18360 authenticatee.cpp:299] Authentication success
3: I1128 17:03:38.330775 18362 master.cpp:8342] Successfully authenticated principal 'test-principal' at slave(279)@172.17.0.4:46683
3: I1128 17:03:38.330816 18360 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(578)@172.17.0.4:46683
3: I1128 17:03:38.330960 18355 slave.cpp:1161] Successfully authenticated with master master@172.17.0.4:46683
3: I1128 17:03:38.331207 18355 slave.cpp:1685] Will retry registration in 7.281554ms if necessary
3: I1128 17:03:38.331452 18369 master.cpp:6036] Received register agent message from slave(279)@172.17.0.4:46683 (78dd34898e51)
3: I1128 17:03:38.331496 18369 master.cpp:3872] Authorizing agent with principal 'test-principal'
3: I1128 17:03:38.331902 18372 master.cpp:6098] Authorized registration of agent at slave(279)@172.17.0.4:46683 (78dd34898e51)
3: I1128 17:03:38.331996 18372 master.cpp:6191] Registering agent at slave(279)@172.17.0.4:46683 (78dd34898e51) with id 3b3c9823-295a-4357-80fa-c07382f48ee0-S0
3: I1128 17:03:38.332341 18367 registrar.cpp:495] Applied 1 operations in 70720ns; attempting to update the registry
3: I1128 17:03:38.332876 18367 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1128 17:03:38.333129 18359 master.cpp:6240] Admitted agent 3b3c9823-295a-4357-80fa-c07382f48ee0-S0 at slave(279)@172.17.0.4:46683 (78dd34898e51)
3: I1128 17:03:38.333825 18359 master.cpp:6276] Registered agent 3b3c9823-295a-4357-80fa-c07382f48ee0-S0 at slave(279)@172.17.0.4:46683 (78dd34898e51) with cpus:2; mem:1024; disk:4096; ports:[31000-32000]
3: I1128 17:03:38.333904 18361 slave.cpp:1207] Registered with master master@172.17.0.4:46683; given agent ID 3b3c9823-295a-4357-80fa-c07382f48ee0-S0
3: I1128 17:03:38.334038 18371 task_status_update_manager.cpp:188] Resuming sending task status updates
3: I1128 17:03:38.334110 18364 hierarchical.cpp:600] Added agent 3b3c9823-295a-4357-80fa-c07382f48ee0-S0 (78dd34898e51) with cpus:2; mem:1024; disk:4096; ports:[31000-32000] (allocated: {})
3: I1128 17:03:38.334223 18361 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_eF524D/meta/slaves/3b3c9823-295a-4357-80fa-c07382f48ee0-S0/slave.info'
3: I1128 17:03:38.334391 18364 hierarchical.cpp:1457] Performed allocation for 1 agents in 148381ns
3: I1128 17:03:38.334614 18361 slave.cpp:1298] Forwarding total oversubscribed resources {}
3: I1128 17:03:38.334813 18354 master.cpp:7091] Received update of agent 3b3c9823-295a-4357-80fa-c07382f48ee0-S0 at slave(279)@172.17.0.4:46683 (78dd34898e51) with total oversubscribed resources {}
3: I1128 17:03:38.334985 18354 master.cpp:7109] Ignoring update on agent 3b3c9823-295a-4357-80fa-c07382f48ee0-S0 at slave(279)@172.17.0.4:46683 (78dd34898e51) as it reports no changes
3: W1128 17:03:38.339272 18350 process.cpp:2756] Attempted to spawn already running process files@172.17.0.4:46683
3: I1128 17:03:38.340095 18350 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1128 17:03:38.340549 18350 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1128 17:03:38.340661 18350 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1128 17:03:38.340688 18350 provisioner.cpp:259] Using default backend 'copy'
3: I1128 17:03:38.342598 18350 cluster.cpp:448] Creating default 'local' authorizer
3: I1128 17:03:38.344823 18361 slave.cpp:262] Mesos agent started on (280)@172.17.0.4:46683
3: I1128 17:03:38.344856 18361 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_24UDcU/store/appc" --authenticate_http_executors="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_24UDcU/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_24UDcU/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_secret_key="/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_24UDcU/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_24UDcU/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_24UDcU/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:2; mem:1024; disk:4096; ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_24UDcU" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_WnEDXQ" --zk_session_timeout="10secs"
3: I1128 17:03:38.345217 18361 credentials.hpp:86] Loading credential for authentication from '/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_24UDcU/credential'
3: I1128 17:03:38.345353 18361 slave.cpp:295] Agent using credential for: test-principal
3: I1128 17:03:38.345371 18361 credentials.hpp:37] Loading credentials for authentication from '/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_24UDcU/http_credentials'
3: I1128 17:03:38.345572 18370 hierarchical.cpp:1457] Performed allocation for 1 agents in 127787ns
3: I1128 17:03:38.345615 18361 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1128 17:03:38.345736 18361 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1128 17:03:38.345954 18361 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1128 17:03:38.346066 18361 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1128 17:03:38.346273 18361 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1128 17:03:38.346438 18361 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1128 17:03:38.347882 18361 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":4096.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1128 17:03:38.348084 18361 slave.cpp:601] Agent attributes: [ ]
3: I1128 17:03:38.348094 18361 slave.cpp:610] Agent hostname: 78dd34898e51
3: I1128 17:03:38.348275 18369 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1128 17:03:38.349701 18351 state.cpp:64] Recovering state from '/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_WnEDXQ/meta'
3: I1128 17:03:38.349951 18351 task_status_update_manager.cpp:207] Recovering task status update manager
3: I1128 17:03:38.350111 18371 containerizer.cpp:668] Recovering containerizer
3: I1128 17:03:38.351420 18374 provisioner.cpp:455] Provisioner recovery complete
3: I1128 17:03:38.351861 18369 slave.cpp:6493] Finished recovery
3: I1128 17:03:38.352677 18363 slave.cpp:1007] New master detected at master@172.17.0.4:46683
3: I1128 17:03:38.352720 18367 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1128 17:03:38.352756 18363 slave.cpp:1042] Detecting new master
3: I1128 17:03:38.352921 18363 slave.cpp:1069] Authenticating with master master@172.17.0.4:46683
3: I1128 17:03:38.352988 18363 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1128 17:03:38.353271 18368 authenticatee.cpp:121] Creating new client SASL connection
3: I1128 17:03:38.353555 18357 master.cpp:8312] Authenticating slave(280)@172.17.0.4:46683
3: I1128 17:03:38.353674 18351 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(579)@172.17.0.4:46683
3: I1128 17:03:38.353893 18359 authenticator.cpp:98] Creating new server SASL connection
3: I1128 17:03:38.354110 18362 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1128 17:03:38.354143 18362 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1128 17:03:38.354243 18362 authenticator.cpp:204] Received SASL authentication start
3: I1128 17:03:38.354285 18362 authenticator.cpp:326] Authentication requires more steps
3: I1128 17:03:38.354385 18364 authenticatee.cpp:259] Received SASL authentication step
3: I1128 17:03:38.354503 18352 authenticator.cpp:232] Received SASL authentication step
3: I1128 17:03:38.354532 18352 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '78dd34898e51' server FQDN: '78dd34898e51' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1128 17:03:38.354542 18352 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1128 17:03:38.354576 18352 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1128 17:03:38.354598 18352 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '78dd34898e51' server FQDN: '78dd34898e51' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1128 17:03:38.354612 18352 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1128 17:03:38.354625 18352 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1128 17:03:38.354645 18352 authenticator.cpp:318] Authentication success
3: I1128 17:03:38.354770 18370 authenticatee.cpp:299] Authentication success
3: I1128 17:03:38.354823 18355 master.cpp:8342] Successfully authenticated principal 'test-principal' at slave(280)@172.17.0.4:46683
3: I1128 17:03:38.354858 18371 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(579)@172.17.0.4:46683
3: I1128 17:03:38.355062 18373 slave.cpp:1161] Successfully authenticated with master master@172.17.0.4:46683
3: I1128 17:03:38.355307 18373 slave.cpp:1685] Will retry registration in 14.918395ms if necessary
3: I1128 17:03:38.355473 18372 master.cpp:6036] Received register agent message from slave(280)@172.17.0.4:46683 (78dd34898e51)
3: I1128 17:03:38.355521 18372 master.cpp:3872] Authorizing agent with principal 'test-principal'
3: I1128 17:03:38.355985 18374 master.cpp:6098] Authorized registration of agent at slave(280)@172.17.0.4:46683 (78dd34898e51)
3: I1128 17:03:38.356078 18374 master.cpp:6191] Registering agent at slave(280)@172.17.0.4:46683 (78dd34898e51) with id 3b3c9823-295a-4357-80fa-c07382f48ee0-S1
3: I1128 17:03:38.356438 18369 registrar.cpp:495] Applied 1 operations in 84314ns; attempting to update the registry
3: I1128 17:03:38.356945 18369 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1128 17:03:38.357152 18363 master.cpp:6240] Admitted agent 3b3c9823-295a-4357-80fa-c07382f48ee0-S1 at slave(280)@172.17.0.4:46683 (78dd34898e51)
3: I1128 17:03:38.357755 18363 master.cpp:6276] Registered agent 3b3c9823-295a-4357-80fa-c07382f48ee0-S1 at slave(280)@172.17.0.4:46683 (78dd34898e51) with cpus:2; mem:1024; disk:4096; ports:[31000-32000]
3: I1128 17:03:38.357828 18357 slave.cpp:1207] Registered with master master@172.17.0.4:46683; given agent ID 3b3c9823-295a-4357-80fa-c07382f48ee0-S1
3: I1128 17:03:38.357966 18354 task_status_update_manager.cpp:188] Resuming sending task status updates
3: I1128 17:03:38.358026 18351 hierarchical.cpp:600] Added agent 3b3c9823-295a-4357-80fa-c07382f48ee0-S1 (78dd34898e51) with cpus:2; mem:1024; disk:4096; ports:[31000-32000] (allocated: {})
3: I1128 17:03:38.358275 18351 hierarchical.cpp:1457] Performed allocation for 1 agents in 120752ns
3: I1128 17:03:38.358294 18357 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/MasterAllocatorTest_0_RebalancedForUpdatedWeights_WnEDXQ/meta/slaves/3b3c9823-295a-4357-80fa-c07382f48ee0-S1/slave.info'
3: I1128 17:03:38.358989 18357 slave.cpp:1298] Forwarding total oversubscribed resources {}
3: I1128 17:03:38.359225 18364 master.cpp:7091] Received update of agent 3b3c9823-295a-4357-80fa-c07382f48ee0-S1 at slave(280)@172.17.0.4:46683 (78dd34898e51) with total oversubscribed resources {}
3: I1128 17:03:38.359362 18364 master.cpp:7109] Ignoring update on agent 3b3c9823-295a-4357-80fa-c07382f48ee0-S1 at slave(280)@172.17.0.4:46683 (78dd34898e51) as it reports no changes
3: W1128 17:03:38.363682 18350 process.cpp:2756] Attempted to spawn already running process files@172.17.0.4:46683
3: I1128 17:03:38.364506 18350 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1128 17:03:38.364950 18350 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1128 17:03:38.365057 18350 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1128 17:03:38.365085 18350 provisioner.cpp:259] Using default backend 'copy'
3: I1128 17:03:38.367208 18350 cluster.cpp:448] Creating default 'local' authorizer
3: I1128 17:03:38.369549 18357 slave.cpp:262] Mesos agent started on (281)@172.17.0.4:46683
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1511886992-28042
Error response from daemon: conflict: unable to remove repository reference "mesos-1511886992-28042" (must force) - container 78dd34898e51 is using its referenced image e77e72399f60
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos-Buildbot » cmake,clang,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4507
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4507/display/redirect?page=changes>