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/06/26 07:49:41 UTC
Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2) #3837
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)/3837/display/redirect?page=changes>
Changes:
[bmahler] Removed temporary MULTI_ROLE implementation logic in the master.
------------------------------------------
[...truncated 20.49 MB...]
I0626 07:49:28.961113 2587 authenticatee.cpp:259] Received SASL authentication step
I0626 07:49:28.961261 2575 authenticator.cpp:232] Received SASL authentication step
I0626 07:49:28.961294 2575 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '819058182efc' server FQDN: '819058182efc' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0626 07:49:28.961308 2575 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0626 07:49:28.961354 2575 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0626 07:49:28.961374 2575 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '819058182efc' server FQDN: '819058182efc' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0626 07:49:28.961382 2575 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0626 07:49:28.961387 2575 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0626 07:49:28.961402 2575 authenticator.cpp:318] Authentication success
I0626 07:49:28.961501 2572 authenticatee.cpp:299] Authentication success
I0626 07:49:28.961647 2582 master.cpp:7670] Successfully authenticated principal 'test-principal' at slave(537)@172.17.0.10:40078
I0626 07:49:28.961706 2587 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1085)@172.17.0.10:40078
I0626 07:49:28.961932 2570 slave.cpp:1103] Successfully authenticated with master master@172.17.0.10:40078
I0626 07:49:28.962129 2570 slave.cpp:1502] Reregistering completed framework ce7c897e-a0de-4d73-8fa0-3aea3c560066-0000
I0626 07:49:28.962481 2570 slave.cpp:1545] Will retry registration in 15.946724ms if necessary
I0626 07:49:28.962880 2591 master.cpp:5888] Received re-register agent message from agent ce7c897e-a0de-4d73-8fa0-3aea3c560066-S0 at slave(537)@172.17.0.10:40078 (819058182efc)
I0626 07:49:28.963205 2591 master.cpp:3742] Authorizing agent with principal 'test-principal'
I0626 07:49:28.963917 2577 master.cpp:5957] Authorized re-registration of agent ce7c897e-a0de-4d73-8fa0-3aea3c560066-S0 at slave(537)@172.17.0.10:40078 (819058182efc)
I0626 07:49:28.964071 2577 master.cpp:6008] Re-registering agent ce7c897e-a0de-4d73-8fa0-3aea3c560066-S0 at slave(536)@172.17.0.10:40078 (819058182efc)
I0626 07:49:28.964363 2570 slave.cpp:1249] Re-registered with master master@172.17.0.10:40078
I0626 07:49:28.964457 2578 status_update_manager.cpp:184] Resuming sending status updates
I0626 07:49:28.964485 2570 slave.cpp:1286] Forwarding total oversubscribed resources {}
I0626 07:49:28.964486 2577 master.cpp:6419] Sending updated checkpointed resources {} to agent ce7c897e-a0de-4d73-8fa0-3aea3c560066-S0 at slave(537)@172.17.0.10:40078 (819058182efc)
I0626 07:49:28.964511 2584 hierarchical.cpp:703] Agent ce7c897e-a0de-4d73-8fa0-3aea3c560066-S0 reactivated
I0626 07:49:28.964598 2570 slave.cpp:3371] Ignoring new checkpointed resources identical to the current version: {}
I0626 07:49:28.964707 2577 master.cpp:6508] Received update of agent ce7c897e-a0de-4d73-8fa0-3aea3c560066-S0 at slave(537)@172.17.0.10:40078 (819058182efc) with total oversubscribed resources {}
I0626 07:49:29.353165 2575 hierarchical.cpp:2028] No inverse offers to send out!
I0626 07:49:29.353292 2575 hierarchical.cpp:1493] Performed allocation for 1 agents in 1.998052ms
I0626 07:49:29.353930 2584 master.cpp:7470] Sending 1 offers to framework ce7c897e-a0de-4d73-8fa0-3aea3c560066-0000 (default) at scheduler-c98cd0cb-b0c2-4462-9440-9425dc89cf5b@172.17.0.10:40078
I0626 07:49:29.354795 2591 sched.cpp:933] Scheduler::resourceOffers took 163589ns
I0626 07:49:29.356009 2567 sched.cpp:2021] Asked to stop the driver
I0626 07:49:29.356142 2591 sched.cpp:1203] Stopping framework ce7c897e-a0de-4d73-8fa0-3aea3c560066-0000
I0626 07:49:29.356472 2580 master.cpp:8151] Processing TEARDOWN call for framework ce7c897e-a0de-4d73-8fa0-3aea3c560066-0000 (default) at scheduler-c98cd0cb-b0c2-4462-9440-9425dc89cf5b@172.17.0.10:40078
I0626 07:49:29.356521 2580 master.cpp:8163] Removing framework ce7c897e-a0de-4d73-8fa0-3aea3c560066-0000 (default) at scheduler-c98cd0cb-b0c2-4462-9440-9425dc89cf5b@172.17.0.10:40078
I0626 07:49:29.356546 2580 master.cpp:3203] Deactivating framework ce7c897e-a0de-4d73-8fa0-3aea3c560066-0000 (default) at scheduler-c98cd0cb-b0c2-4462-9440-9425dc89cf5b@172.17.0.10:40078
I0626 07:49:29.356875 2586 hierarchical.cpp:410] Deactivated framework ce7c897e-a0de-4d73-8fa0-3aea3c560066-0000
I0626 07:49:29.358172 2577 hierarchical.cpp:1177] 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 ce7c897e-a0de-4d73-8fa0-3aea3c560066-S0 from framework ce7c897e-a0de-4d73-8fa0-3aea3c560066-0000
I0626 07:49:29.358238 2586 slave.cpp:3136] Asked to shut down framework ce7c897e-a0de-4d73-8fa0-3aea3c560066-0000 by master@172.17.0.10:40078
I0626 07:49:29.358299 2586 slave.cpp:3151] Cannot shut down unknown framework ce7c897e-a0de-4d73-8fa0-3aea3c560066-0000
I0626 07:49:29.358841 2588 hierarchical.cpp:353] Removed framework ce7c897e-a0de-4d73-8fa0-3aea3c560066-0000
I0626 07:49:29.360148 2575 slave.cpp:818] Agent terminating
I0626 07:49:29.369366 2574 master.cpp:1158] Master terminating
I0626 07:49:29.370623 2569 hierarchical.cpp:620] Removed agent ce7c897e-a0de-4d73-8fa0-3aea3c560066-S0
[ OK ] SlaveRecoveryTest/0.RecoverCompletedExecutor (2041 ms)
[ RUN ] SlaveRecoveryTest/0.CleanupExecutor
I0626 07:49:29.381054 2567 cluster.cpp:162] Creating default 'local' authorizer
I0626 07:49:29.384132 2571 master.cpp:438] Master c830d7a6-57c7-49e4-9969-e73243caa3c7 (819058182efc) started on 172.17.0.10:40078
I0626 07:49:29.384161 2571 master.cpp:440] 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/Gcg9gd/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/Gcg9gd/master" --zk_session_timeout="10secs"
I0626 07:49:29.384503 2571 master.cpp:490] Master only allowing authenticated frameworks to register
I0626 07:49:29.384519 2571 master.cpp:504] Master only allowing authenticated agents to register
I0626 07:49:29.384526 2571 master.cpp:517] Master only allowing authenticated HTTP frameworks to register
I0626 07:49:29.384534 2571 credentials.hpp:37] Loading credentials for authentication from '/tmp/Gcg9gd/credentials'
I0626 07:49:29.384845 2571 master.cpp:562] Using default 'crammd5' authenticator
I0626 07:49:29.385004 2571 http.cpp:974] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0626 07:49:29.385356 2571 http.cpp:974] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0626 07:49:29.385794 2571 http.cpp:974] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0626 07:49:29.386157 2571 master.cpp:642] Authorization enabled
I0626 07:49:29.386503 2578 whitelist_watcher.cpp:77] No whitelist given
I0626 07:49:29.386603 2586 hierarchical.cpp:169] Initialized hierarchical allocator process
I0626 07:49:29.389976 2570 master.cpp:2161] Elected as the leading master!
I0626 07:49:29.390056 2570 master.cpp:1700] Recovering from registrar
I0626 07:49:29.390324 2582 registrar.cpp:345] Recovering registrar
I0626 07:49:29.391288 2582 registrar.cpp:389] Successfully fetched the registry (0B) in 910080ns
I0626 07:49:29.391463 2582 registrar.cpp:493] Applied 1 operations in 49420ns; attempting to update the registry
I0626 07:49:29.392330 2582 registrar.cpp:550] Successfully updated the registry in 744192ns
I0626 07:49:29.392524 2582 registrar.cpp:422] Successfully recovered registrar
I0626 07:49:29.393293 2586 hierarchical.cpp:207] Skipping recovery of hierarchical allocator: nothing to recover
I0626 07:49:29.393314 2580 master.cpp:1799] Recovered 0 agents from the registry (132B); allowing 10mins for agents to re-register
I0626 07:49:29.397088 2567 containerizer.cpp:230] Using isolation: posix/cpu,posix/mem,filesystem/posix,network/cni,environment_secret
W0626 07:49:29.397668 2567 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0626 07:49:29.397778 2567 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0626 07:49:29.397816 2567 provisioner.cpp:255] Using default backend 'copy'
I0626 07:49:29.402848 2567 cluster.cpp:448] Creating default 'local' authorizer
I0626 07:49:29.404809 2568 slave.cpp:249] Mesos agent started on (538)@172.17.0.10:40078
I0626 07:49:29.404832 2568 slave.cpp:250] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/SlaveRecoveryTest_0_CleanupExecutor_2VEkSb/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/SlaveRecoveryTest_0_CleanupExecutor_2VEkSb/credential" --default_role="*" --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/SlaveRecoveryTest_0_CleanupExecutor_2VEkSb/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/SlaveRecoveryTest_0_CleanupExecutor_2VEkSb/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/SlaveRecoveryTest_0_CleanupExecutor_2VEkSb/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/SlaveRecoveryTest_0_CleanupExecutor_2VEkSb/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/SlaveRecoveryTest_0_CleanupExecutor_2VEkSb" --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/SlaveRecoveryTest_0_CleanupExecutor_LrdJzc"
I0626 07:49:29.405421 2568 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveRecoveryTest_0_CleanupExecutor_2VEkSb/credential'
I0626 07:49:29.405755 2568 slave.cpp:282] Agent using credential for: test-principal
I0626 07:49:29.405776 2568 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveRecoveryTest_0_CleanupExecutor_2VEkSb/http_credentials'
I0626 07:49:29.406249 2568 http.cpp:974] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
I0626 07:49:29.406406 2568 http.cpp:995] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
I0626 07:49:29.406551 2567 sched.cpp:232] Version: 1.4.0
I0626 07:49:29.406956 2568 http.cpp:974] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0626 07:49:29.407178 2568 http.cpp:995] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
I0626 07:49:29.407418 2569 sched.cpp:336] New master detected at master@172.17.0.10:40078
I0626 07:49:29.407543 2569 sched.cpp:407] Authenticating with master master@172.17.0.10:40078
I0626 07:49:29.407560 2569 sched.cpp:414] Using default CRAM-MD5 authenticatee
I0626 07:49:29.407690 2568 http.cpp:974] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
I0626 07:49:29.407924 2568 http.cpp:995] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
I0626 07:49:29.407935 2584 authenticatee.cpp:121] Creating new client SASL connection
I0626 07:49:29.408359 2585 master.cpp:7640] Authenticating scheduler-90fac36e-761f-4a85-a01e-0ea7efa7e36e@172.17.0.10:40078
I0626 07:49:29.408521 2571 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1086)@172.17.0.10:40078
I0626 07:49:29.408885 2587 authenticator.cpp:98] Creating new server SASL connection
I0626 07:49:29.409255 2584 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0626 07:49:29.409281 2584 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0626 07:49:29.409559 2590 authenticator.cpp:204] Received SASL authentication start
I0626 07:49:29.409622 2590 authenticator.cpp:326] Authentication requires more steps
I0626 07:49:29.409772 2576 authenticatee.cpp:259] Received SASL authentication step
I0626 07:49:29.409952 2580 authenticator.cpp:232] Received SASL authentication step
I0626 07:49:29.410009 2580 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '819058182efc' server FQDN: '819058182efc' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0626 07:49:29.410032 2580 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0626 07:49:29.410068 2580 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0626 07:49:29.410094 2580 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '819058182efc' server FQDN: '819058182efc' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0626 07:49:29.410109 2580 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0626 07:49:29.410127 2580 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0626 07:49:29.410146 2580 authenticator.cpp:318] Authentication success
I0626 07:49:29.409955 2568 slave.cpp:553] 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"}]
I0626 07:49:29.410223 2568 slave.cpp:561] Agent attributes: [ ]
I0626 07:49:29.410235 2568 slave.cpp:566] Agent hostname: 819058182efc
I0626 07:49:29.410235 2590 authenticatee.cpp:299] Authentication success
I0626 07:49:29.410305 2581 master.cpp:7670] Successfully authenticated principal 'test-principal' at scheduler-90fac36e-761f-4a85-a01e-0ea7efa7e36e@172.17.0.10:40078
I0626 07:49:29.410396 2584 status_update_manager.cpp:177] Pausing sending status updates
I0626 07:49:29.410485 2590 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1086)@172.17.0.10:40078
I0626 07:49:29.410635 2582 sched.cpp:513] Successfully authenticated with master master@172.17.0.10:40078
I0626 07:49:29.410655 2582 sched.cpp:836] Sending SUBSCRIBE call to master@172.17.0.10:40078
I0626 07:49:29.410874 2582 sched.cpp:869] Will retry registration in 550.606324ms if necessary
I0626 07:49:29.411056 2590 master.cpp:2853] Received SUBSCRIBE call for framework 'default' at scheduler-90fac36e-761f-4a85-a01e-0ea7efa7e36e@172.17.0.10:40078
I0626 07:49:29.411154 2590 master.cpp:2197] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
I0626 07:49:29.411808 2578 master.cpp:2933] Subscribing framework default with checkpointing enabled and capabilities [ RESERVATION_REFINEMENT ]
I0626 07:49:29.412372 2574 state.cpp:64] Recovering state from '/tmp/SlaveRecoveryTest_0_CleanupExecutor_LrdJzc/meta'
I0626 07:49:29.412470 2581 sched.cpp:759] Framework registered with c830d7a6-57c7-49e4-9969-e73243caa3c7-0000
I0626 07:49:29.412514 2581 sched.cpp:773] Scheduler::registered took 23304ns
I0626 07:49:29.412575 2580 hierarchical.cpp:301] Added framework c830d7a6-57c7-49e4-9969-e73243caa3c7-0000
I0626 07:49:29.412770 2580 hierarchical.cpp:1938] No allocations performed
I0626 07:49:29.412808 2580 hierarchical.cpp:2028] No inverse offers to send out!
I0626 07:49:29.412809 2570 status_update_manager.cpp:203] Recovering status update manager
I0626 07:49:29.412840 2580 hierarchical.cpp:1493] Performed allocation for 0 agents in 116593ns
I0626 07:49:29.413033 2575 containerizer.cpp:582] Recovering containerizer
I0626 07:49:29.414871 2570 provisioner.cpp:416] Provisioner recovery complete
I0626 07:49:29.415416 2587 slave.cpp:6168] Finished recovery
I0626 07:49:29.416055 2587 slave.cpp:6350] Querying resource estimator for oversubscribable resources
I0626 07:49:29.416385 2578 status_update_manager.cpp:177] Pausing sending status updates
I0626 07:49:29.416391 2587 slave.cpp:946] New master detected at master@172.17.0.10:40078
I0626 07:49:29.416483 2587 slave.cpp:981] Detecting new master
I0626 07:49:29.416616 2587 slave.cpp:6364] Received oversubscribable resources {} from the resource estimator
I0626 07:49:29.422771 2571 slave.cpp:1008] Authenticating with master master@172.17.0.10:40078
I0626 07:49:29.422861 2571 slave.cpp:1019] Using default CRAM-MD5 authenticatee
I0626 07:49:29.423133 2582 authenticatee.cpp:121] Creating new client SASL connection
I0626 07:49:29.423447 2575 master.cpp:7640] Authenticating slave(538)@172.17.0.10:40078
I0626 07:49:29.423591 2591 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1087)@172.17.0.10:40078
I0626 07:49:29.423856 2576 authenticator.cpp:98] Creating new server SASL connection
I0626 07:49:29.424278 2586 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0626 07:49:29.424301 2586 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0626 07:49:29.424424 2587 authenticator.cpp:204] Received SASL authentication start
I0626 07:49:29.424470 2587 authenticator.cpp:326] Authentication requires more steps
I0626 07:49:29.424595 2576 authenticatee.cpp:259] Received SASL authentication step
I0626 07:49:29.424767 2588 authenticator.cpp:232] Received SASL authentication step
I0626 07:49:29.424815 2588 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '819058182efc' server FQDN: '819058182efc' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0626 07:49:29.424829 2588 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0626 07:49:29.424881 2588 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0626 07:49:29.424901 2588 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '819058182efc' server FQDN: '819058182efc' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0626 07:49:29.424923 2588 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0626 07:49:29.424929 2588 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0626 07:49:29.424945 2588 authenticator.cpp:318] Authentication success
I0626 07:49:29.425072 2569 authenticatee.cpp:299] Authentication success
I0626 07:49:29.425236 2579 master.cpp:7670] Successfully authenticated principal 'test-principal' at slave(538)@172.17.0.10:40078
I0626 07:49:29.425276 2584 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1087)@172.17.0.10:40078
I0626 07:49:29.425670 2582 slave.cpp:1103] Successfully authenticated with master master@172.17.0.10:40078
I0626 07:49:29.425933 2582 slave.cpp:1545] Will retry registration in 2.451997ms if necessary
I0626 07:49:29.426172 2581 master.cpp:5602] Received register agent message from slave(538)@172.17.0.10:40078 (819058182efc)
I0626 07:49:29.426343 2581 master.cpp:3742] Authorizing agent with principal 'test-principal'
I0626 07:49:29.426746 2589 master.cpp:5662] Authorized registration of agent at slave(538)@172.17.0.10:40078 (819058182efc)
I0626 07:49:29.426870 2589 master.cpp:5741] Registering agent at slave(538)@172.17.0.10:40078 (819058182efc) with id c830d7a6-57c7-49e4-9969-e73243caa3c7-S0
I0626 07:49:29.427335 2572 registrar.cpp:493] Applied 1 operations in 70591ns; attempting to update the registry
I0626 07:49:29.428051 2572 registrar.cpp:550] Successfully updated the registry in 658176ns
I0626 07:49:29.428275 2585 master.cpp:5788] Admitted agent c830d7a6-57c7-49e4-9969-e73243caa3c7-S0 at slave(538)@172.17.0.10:40078 (819058182efc)
I0626 07:49:29.428849 2573 slave.cpp:4866] Received ping from slave-observer(523)@172.17.0.10:40078
I0626 07:49:29.429090 2573 slave.cpp:1149] Registered with master master@172.17.0.10:40078; given agent ID c830d7a6-57c7-49e4-9969-e73243caa3c7-S0
I0626 07:49:29.428957 2585 master.cpp:5819] Registered agent c830d7a6-57c7-49e4-9969-e73243caa3c7-S0 at slave(538)@172.17.0.10:40078 (819058182efc) 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"}]
I0626 07:49:29.429277 2591 status_update_manager.cpp:184] Resuming sending status updates
I0626 07:49:29.429260 2583 hierarchical.cpp:587] Added agent c830d7a6-57c7-49e4-9969-e73243caa3c7-S0 (819058182efc) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I0626 07:49:29.429452 2573 slave.cpp:1169] Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_LrdJzc/meta/slaves/c830d7a6-57c7-49e4-9969-e73243caa3c7-S0/slave.info'
I0626 07:49:29.429759 2573 slave.cpp:1207] Forwarding total oversubscribed resources {}
I0626 07:49:29.429924 2578 master.cpp:6508] Received update of agent c830d7a6-57c7-49e4-9969-e73243caa3c7-S0 at slave(538)@172.17.0.10:40078 (819058182efc) with total oversubscribed resources {}
I0626 07:49:29.430459 2583 hierarchical.cpp:2028] No inverse offers to send out!
I0626 07:49:29.430501 2583 hierarchical.cpp:1493] Performed allocation for 1 agents in 1.072724ms
I0626 07:49:29.430886 2588 master.cpp:7470] Sending 1 offers to framework c830d7a6-57c7-49e4-9969-e73243caa3c7-0000 (default) at scheduler-90fac36e-761f-4a85-a01e-0ea7efa7e36e@172.17.0.10:40078
I0626 07:49:29.431452 2573 sched.cpp:933] Scheduler::resourceOffers took 166198ns
I0626 07:49:29.433703 2586 master.cpp:3957] Processing ACCEPT call for offers: [ c830d7a6-57c7-49e4-9969-e73243caa3c7-O0 ] on agent c830d7a6-57c7-49e4-9969-e73243caa3c7-S0 at slave(538)@172.17.0.10:40078 (819058182efc) for framework c830d7a6-57c7-49e4-9969-e73243caa3c7-0000 (default) at scheduler-90fac36e-761f-4a85-a01e-0ea7efa7e36e@172.17.0.10:40078
I0626 07:49:29.433805 2586 master.cpp:3469] Authorizing framework principal 'test-principal' to launch task 1d69a334-0c75-46d6-93d6-d90f0ff641ae
I0626 07:49:29.436152 2586 master.cpp:9518] Adding task 1d69a334-0c75-46d6-93d6-d90f0ff641ae 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 c830d7a6-57c7-49e4-9969-e73243caa3c7-S0 at slave(538)@172.17.0.10:40078 (819058182efc)
I0626 07:49:29.436734 2586 master.cpp:4684] Launching task 1d69a334-0c75-46d6-93d6-d90f0ff641ae of framework c830d7a6-57c7-49e4-9969-e73243caa3c7-0000 (default) at scheduler-90fac36e-761f-4a85-a01e-0ea7efa7e36e@172.17.0.10:40078 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 c830d7a6-57c7-49e4-9969-e73243caa3c7-S0 at slave(538)@172.17.0.10:40078 (819058182efc)
I0626 07:49:29.437685 2584 slave.cpp:1670] Got assigned task '1d69a334-0c75-46d6-93d6-d90f0ff641ae' for framework c830d7a6-57c7-49e4-9969-e73243caa3c7-0000
I0626 07:49:29.437937 2584 slave.cpp:7046] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_LrdJzc/meta/slaves/c830d7a6-57c7-49e4-9969-e73243caa3c7-S0/frameworks/c830d7a6-57c7-49e4-9969-e73243caa3c7-0000/framework.info'
I0626 07:49:29.438390 2584 slave.cpp:7057] Checkpointing framework pid 'scheduler-90fac36e-761f-4a85-a01e-0ea7efa7e36e@172.17.0.10:40078' to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_LrdJzc/meta/slaves/c830d7a6-57c7-49e4-9969-e73243caa3c7-S0/frameworks/c830d7a6-57c7-49e4-9969-e73243caa3c7-0000/framework.pid'
I0626 07:49:29.439249 2584 slave.cpp:1951] Authorizing task '1d69a334-0c75-46d6-93d6-d90f0ff641ae' for framework c830d7a6-57c7-49e4-9969-e73243caa3c7-0000
I0626 07:49:29.439306 2584 slave.cpp:6667] Authorizing framework principal 'test-principal' to launch task 1d69a334-0c75-46d6-93d6-d90f0ff641ae
I0626 07:49:29.439451 2589 hierarchical.cpp:912] Updated allocation of framework c830d7a6-57c7-49e4-9969-e73243caa3c7-0000 on agent c830d7a6-57c7-49e4-9969-e73243caa3c7-S0 from cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] to cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000]
I0626 07:49:29.440415 2571 slave.cpp:2138] Launching task '1d69a334-0c75-46d6-93d6-d90f0ff641ae' for framework c830d7a6-57c7-49e4-9969-e73243caa3c7-0000
I0626 07:49:29.441406 2571 paths.cpp:577] Trying to chown '/tmp/SlaveRecoveryTest_0_CleanupExecutor_LrdJzc/slaves/c830d7a6-57c7-49e4-9969-e73243caa3c7-S0/frameworks/c830d7a6-57c7-49e4-9969-e73243caa3c7-0000/executors/1d69a334-0c75-46d6-93d6-d90f0ff641ae/runs/bb8cb077-4350-4eaa-b3f4-203a2769a8e1' to user 'mesos'
I0626 07:49:29.441761 2571 slave.cpp:7515] Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_LrdJzc/meta/slaves/c830d7a6-57c7-49e4-9969-e73243caa3c7-S0/frameworks/c830d7a6-57c7-49e4-9969-e73243caa3c7-0000/executors/1d69a334-0c75-46d6-93d6-d90f0ff641ae/executor.info'
F0626 07:49:29.442878 2571 paths.cpp:564] CHECK_SOME(symlink): No space left on device Failed to symlink directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_LrdJzc/meta/slaves/c830d7a6-57c7-49e4-9969-e73243caa3c7-S0/frameworks/c830d7a6-57c7-49e4-9969-e73243caa3c7-0000/executors/1d69a334-0c75-46d6-93d6-d90f0ff641ae/runs/bb8cb077-4350-4eaa-b3f4-203a2769a8e1' to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_LrdJzc/meta/slaves/c830d7a6-57c7-49e4-9969-e73243caa3c7-S0/frameworks/c830d7a6-57c7-49e4-9969-e73243caa3c7-0000/executors/1d69a334-0c75-46d6-93d6-d90f0ff641ae/runs/latest'
*** Check failure stack trace: ***
@ 0x2ae531af59fd google::LogMessage::Fail()
@ 0x2ae531af789d google::LogMessage::SendToLog()
@ 0x2ae531af55ec google::LogMessage::Flush()
@ 0x2ae531af81be google::LogMessageFatal::~LogMessageFatal()
@ 0x2546bb8 _CheckFatal::~_CheckFatal()
@ 0x2ae52d7e0f0b mesos::internal::slave::paths::createExecutorDirectory()
@ 0x2ae52d828bd1 mesos::internal::slave::Executor::checkpointExecutor()
@ 0x2ae52d824a5a mesos::internal::slave::Framework::addExecutor()
@ 0x2ae52d7fc321 mesos::internal::slave::Slave::__run()
@ 0x2ae52d879c33 _ZZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS_6FutureISt4listIbSaIbEEEERKNS1_13FrameworkInfoERKNS1_12ExecutorInfoERK6OptionINS1_8TaskInfoEERKSI_INS1_13TaskGroupInfoEES9_SC_SF_SK_SO_EEvRKNS_3PIDIT_EEMSS_FvT0_T1_T2_T3_T4_ET5_T6_T7_T8_T9_ENKUlPNS_11ProcessBaseEE_clES19_
@ 0x2ae52d8c429c _ZNSt17_Function_handlerIFvPN7process11ProcessBaseEEZNS0_8dispatchIN5mesos8internal5slave5SlaveERKNS0_6FutureISt4listIbSaIbEEEERKNS5_13FrameworkInfoERKNS5_12ExecutorInfoERK6OptionINS5_8TaskInfoEERKSM_INS5_13TaskGroupInfoEESD_SG_SJ_SO_SS_EEvRKNS0_3PIDIT_EEMSW_FvT0_T1_T2_T3_T4_ET5_T6_T7_T8_T9_EUlS2_E_E9_M_invokeERKSt9_Any_dataS2_
@ 0x2ae530345369 std::function<>::operator()()
@ 0x2ae5303239df process::ProcessBase::visit()
@ 0x2ae53032f548 process::DispatchEvent::visit()
@ 0x25601f8 process::ProcessBase::serve()
@ 0x2ae53031fca0 process::ProcessManager::resume()
@ 0x2ae53031be74 _ZZN7process14ProcessManager12init_threadsEvENKUt_clEv
@ 0x2ae53032dacc _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUt_vEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE
@ 0x2ae53032da23 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUt_vEEclEv
@ 0x2ae53032d9bc _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUt_vEEE6_M_runEv
@ 0x2ae532c28a60 (unknown)
@ 0x2ae532961184 start_thread
@ 0x2ae533494ffd (unknown)
make[3]: Leaving directory `/mesos/build'
make[3]: *** [CMakeFiles/check] Aborted (core dumped)
make[2]: *** [CMakeFiles/check.dir/all] Error 2
make[2]: Leaving directory `/mesos/build'
make[1]: *** [CMakeFiles/check.dir/rule] Error 2
make[1]: Leaving directory `/mesos/build'
make: *** [check] Error 2
+ docker rmi mesos-1498460530-10488
Untagged: mesos-1498460530-10488:latest
Deleted: sha256:5730a9781862435a6e5e0449f50951ad129d87d81802f192c944490c5a80de9e
Deleted: sha256:14e0acdfc53cedf25fca166a27c129b3a95a17441de71cdf05982861865626b5
Deleted: sha256:0ea5c43af586b7ae82cd84499b03ae74b7282b5e847bb8ba29d0a63e887504e8
Deleted: sha256:b0ab4a89c49346586a5e81a40ec40240838430b36cfc8381e14cb4558b7d6d57
Deleted: sha256:f3a7b2dd42d3fff1421c8e9496d84476e2b8e6f81fa6dd944547ecd42baa4988
Deleted: sha256:690efe2f5054bf8e1530a73d6ce37dce1af0e86264a883384deedc61ef228a7d
Deleted: sha256:5a1581a5a28b85786fd47b5779d9e427915941fff4a4ee35bd2570d0f9e3b7c7
Deleted: sha256:fc04308bc58ee94fec3ccdfe03f08214ff197db6f5edcdd5e30497538276ddf5
Deleted: sha256:a9d0414db56a3561b56d082bc8191c2c604e83d67bf791de84f29800ad5c8134
Deleted: sha256:fa34f412d61f2adfa6ebbfdb62723e032cec92e8f27f691b11f2ca4fd9fb85e8
Deleted: sha256:2b17f39ea6baa0dc60ebabdd8f65aad8310be65ade54b4769456f4684518904a
Deleted: sha256:376b0f31ba72bfeb8fcdcdbb92ae9106419edfb67450e4446fe73b3f9e10f884
Deleted: sha256:da4341bcf1b338893e6d33965c9cfa846f248a368f74b50a10f2c7b454c19258
Deleted: sha256:eb3469868812b4dffbcc985ebf23216aca7fa41008a28df5a37c8f4bb96ee76d
Deleted: sha256:6e67a5beb8c3fe74d945ca343b150636458b6585788af00f535b57eef4d94a08
Deleted: sha256:2d2497f18bc72f4a4b4fb4fed45b3bae9bc0a2012924288fdebbc22cc7f37eb9
Deleted: sha256:fbfcd0b7ec46f9243f514de7cdd709c9d8d788c989bceda35ebc5aeca1edc754
Deleted: sha256:c5bbaa41d080f45d1c6e615b32a02ba6777166617c558e5d685d132996096484
Deleted: sha256:86708f574f2ac8c1d4567beeb3e9085c23f192eb1350c252aef9cfd1336ef736
Deleted: sha256:21667aaeb882c958ac4df2ba95a99cf84815f219aa31cdeb9629e99854d40cc3
Deleted: sha256:13bef1fdd2dbfd73bbb43cd24e7da3d8aaa530f75a0c57c2c18b11250c5a8e3a
Deleted: sha256:f0ed0d5607546fe7ed0944b2caf1300984b1022e928f0da187895be3558724f5
Deleted: sha256:f641a6587bb44a3ba614e4bfc6d3149f52f9788172876e4fa59a53b8d145cb84
Deleted: sha256:e2ffda9c098a8bbd7f2ee85bef54095f6f7669180206b8cfc0a9b157450d0422
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos-Buildbot » cmake,gcc,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2) #3838
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)/3838/display/redirect?page=changes>