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/21 15:40:18 UTC
Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers,GLOG_v=1 MESOS_VERBOSE=1,centos:7,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4485
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=centos%3A7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4485/display/redirect>
------------------------------------------
[...truncated 18.71 MB...]
3: I1121 15:40:13.385998 16013 master.cpp:448] Master d5ac30b4-1905-4388-b029-eb14d3a763d3 (1c0e8cf637bb) started on 172.17.0.7:46794
3: I1121 15:40:13.386015 16013 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/lSMCsh/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/lSMCsh/master" --zk_session_timeout="10secs"
3: I1121 15:40:13.386283 16013 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1121 15:40:13.386291 16013 master.cpp:505] Master only allowing authenticated agents to register
3: I1121 15:40:13.386293 16013 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1121 15:40:13.386297 16013 credentials.hpp:37] Loading credentials for authentication from '/tmp/lSMCsh/credentials'
3: I1121 15:40:13.386512 16013 master.cpp:555] Using default 'crammd5' authenticator
3: I1121 15:40:13.386626 16013 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1121 15:40:13.386735 16013 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1121 15:40:13.386838 16013 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1121 15:40:13.386931 16013 master.cpp:634] Authorization enabled
3: I1121 15:40:13.387086 15995 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1121 15:40:13.387090 16008 whitelist_watcher.cpp:77] No whitelist given
3: I1121 15:40:13.389410 16005 master.cpp:2215] Elected as the leading master!
3: I1121 15:40:13.389439 16005 master.cpp:1695] Recovering from registrar
3: I1121 15:40:13.389603 16015 registrar.cpp:347] Recovering registrar
3: I1121 15:40:13.390228 16015 registrar.cpp:391] Successfully fetched the registry (0B) in 586240ns
3: I1121 15:40:13.390319 16015 registrar.cpp:495] Applied 1 operations in 25544ns; attempting to update the registry
3: I1121 15:40:13.390836 16015 registrar.cpp:552] Successfully updated the registry in 467968ns
3: I1121 15:40:13.390946 16015 registrar.cpp:424] Successfully recovered registrar
3: I1121 15:40:13.391326 16014 master.cpp:1808] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1121 15:40:13.391340 16011 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: W1121 15:40:13.391969 15992 process.cpp:2756] Attempted to spawn already running process version@172.17.0.7:46794
3: I1121 15:40:13.392848 15992 sched.cpp:232] Version: 1.5.0
3: I1121 15:40:13.393450 16016 sched.cpp:336] New master detected at master@172.17.0.7:46794
3: I1121 15:40:13.393540 16016 sched.cpp:396] Authenticating with master master@172.17.0.7:46794
3: I1121 15:40:13.393556 16016 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1121 15:40:13.393800 16009 authenticatee.cpp:121] Creating new client SASL connection
3: I1121 15:40:13.394109 16012 master.cpp:8306] Authenticating scheduler-e8724e06-3115-4dc6-8653-4c250b586684@172.17.0.7:46794
3: I1121 15:40:13.394248 15997 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(985)@172.17.0.7:46794
3: I1121 15:40:13.394505 15998 authenticator.cpp:98] Creating new server SASL connection
3: I1121 15:40:13.394771 16006 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1121 15:40:13.394798 16006 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1121 15:40:13.394893 16006 authenticator.cpp:204] Received SASL authentication start
3: I1121 15:40:13.394946 16006 authenticator.cpp:326] Authentication requires more steps
3: I1121 15:40:13.395076 16004 authenticatee.cpp:259] Received SASL authentication step
3: I1121 15:40:13.395201 16002 authenticator.cpp:232] Received SASL authentication step
3: I1121 15:40:13.395226 16002 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '1c0e8cf637bb' server FQDN: '1c0e8cf637bb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1121 15:40:13.395236 16002 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1121 15:40:13.395257 16002 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1121 15:40:13.395269 16002 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '1c0e8cf637bb' server FQDN: '1c0e8cf637bb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1121 15:40:13.395277 16002 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1121 15:40:13.395282 16002 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1121 15:40:13.395292 16002 authenticator.cpp:318] Authentication success
3: I1121 15:40:13.395367 15993 authenticatee.cpp:299] Authentication success
3: I1121 15:40:13.395418 16000 master.cpp:8336] Successfully authenticated principal 'test-principal' at scheduler-e8724e06-3115-4dc6-8653-4c250b586684@172.17.0.7:46794
3: I1121 15:40:13.395458 16003 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(985)@172.17.0.7:46794
3: I1121 15:40:13.395622 15993 sched.cpp:502] Successfully authenticated with master master@172.17.0.7:46794
3: I1121 15:40:13.395642 15993 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.7:46794
3: I1121 15:40:13.395723 15993 sched.cpp:857] Will retry registration in 886.580701ms if necessary
3: I1121 15:40:13.395879 16001 master.cpp:2963] Received SUBSCRIBE call for framework 'default' at scheduler-e8724e06-3115-4dc6-8653-4c250b586684@172.17.0.7:46794
3: I1121 15:40:13.395952 16001 master.cpp:2280] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
3: I1121 15:40:13.396425 16013 master.cpp:3043] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT, PARTITION_AWARE ]
3: I1121 15:40:13.396888 15995 sched.cpp:751] Framework registered with d5ac30b4-1905-4388-b029-eb14d3a763d3-0000
3: I1121 15:40:13.396971 15995 sched.cpp:765] Scheduler::registered took 54833ns
3: I1121 15:40:13.397014 15994 hierarchical.cpp:306] Added framework d5ac30b4-1905-4388-b029-eb14d3a763d3-0000
3: I1121 15:40:13.397253 15994 hierarchical.cpp:1457] Performed allocation for 0 agents in 76879ns
3: I1121 15:40:13.397644 16004 master.cpp:7790] Performing explicit task state reconciliation for 1 tasks of framework d5ac30b4-1905-4388-b029-eb14d3a763d3-0000 (default) at scheduler-e8724e06-3115-4dc6-8653-4c250b586684@172.17.0.7:46794
3: I1121 15:40:13.397732 16004 master.cpp:7938] Sending explicit reconciliation state TASK_UNKNOWN for task a83f6a90-7372-4175-ac63-e21036e15877 of framework d5ac30b4-1905-4388-b029-eb14d3a763d3-0000 (default) at scheduler-e8724e06-3115-4dc6-8653-4c250b586684@172.17.0.7:46794
3: I1121 15:40:13.397979 16015 sched.cpp:1029] Scheduler::statusUpdate took 52823ns
3: I1121 15:40:13.398205 15992 sched.cpp:2009] Asked to stop the driver
3: I1121 15:40:13.398306 16010 sched.cpp:1191] Stopping framework d5ac30b4-1905-4388-b029-eb14d3a763d3-0000
3: I1121 15:40:13.398502 15999 master.cpp:8813] Processing TEARDOWN call for framework d5ac30b4-1905-4388-b029-eb14d3a763d3-0000 (default) at scheduler-e8724e06-3115-4dc6-8653-4c250b586684@172.17.0.7:46794
3: I1121 15:40:13.398535 15999 master.cpp:8825] Removing framework d5ac30b4-1905-4388-b029-eb14d3a763d3-0000 (default) at scheduler-e8724e06-3115-4dc6-8653-4c250b586684@172.17.0.7:46794
3: I1121 15:40:13.398543 15999 master.cpp:3333] Deactivating framework d5ac30b4-1905-4388-b029-eb14d3a763d3-0000 (default) at scheduler-e8724e06-3115-4dc6-8653-4c250b586684@172.17.0.7:46794
3: I1121 15:40:13.398660 16001 hierarchical.cpp:419] Deactivated framework d5ac30b4-1905-4388-b029-eb14d3a763d3-0000
3: I1121 15:40:13.398947 16013 hierarchical.cpp:358] Removed framework d5ac30b4-1905-4388-b029-eb14d3a763d3-0000
3: I1121 15:40:13.399260 16009 master.cpp:1153] Master terminating
3: [ OK ] ReconciliationTest.UnknownSlave (21 ms)
3: [ RUN ] ReconciliationTest.UnknownTask
3: I1121 15:40:13.404167 15992 cluster.cpp:162] Creating default 'local' authorizer
3: I1121 15:40:13.406828 16002 master.cpp:448] Master 665300a2-2fb6-4dbc-ad91-7c354a208f2b (1c0e8cf637bb) started on 172.17.0.7:46794
3: I1121 15:40:13.406844 16002 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/AhncJq/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/AhncJq/master" --zk_session_timeout="10secs"
3: I1121 15:40:13.407052 16002 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1121 15:40:13.407058 16002 master.cpp:505] Master only allowing authenticated agents to register
3: I1121 15:40:13.407063 16002 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1121 15:40:13.407066 16002 credentials.hpp:37] Loading credentials for authentication from '/tmp/AhncJq/credentials'
3: I1121 15:40:13.407269 16002 master.cpp:555] Using default 'crammd5' authenticator
3: I1121 15:40:13.407372 16002 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1121 15:40:13.407488 16002 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1121 15:40:13.407601 16002 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1121 15:40:13.407698 16002 master.cpp:634] Authorization enabled
3: I1121 15:40:13.407815 16015 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1121 15:40:13.407842 16008 whitelist_watcher.cpp:77] No whitelist given
3: I1121 15:40:13.410010 15994 master.cpp:2215] Elected as the leading master!
3: I1121 15:40:13.410032 15994 master.cpp:1695] Recovering from registrar
3: I1121 15:40:13.410159 15998 registrar.cpp:347] Recovering registrar
3: I1121 15:40:13.410611 15998 registrar.cpp:391] Successfully fetched the registry (0B) in 417792ns
3: I1121 15:40:13.410686 15998 registrar.cpp:495] Applied 1 operations in 18629ns; attempting to update the registry
3: I1121 15:40:13.411106 15998 registrar.cpp:552] Successfully updated the registry in 380928ns
3: I1121 15:40:13.411206 15998 registrar.cpp:424] Successfully recovered registrar
3: I1121 15:40:13.411494 15999 master.cpp:1808] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1121 15:40:13.411531 15996 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: W1121 15:40:13.415313 15992 process.cpp:2756] Attempted to spawn already running process files@172.17.0.7:46794
3: I1121 15:40:13.416100 15992 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1121 15:40:13.416546 15992 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1121 15:40:13.416642 15992 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1121 15:40:13.416667 15992 provisioner.cpp:259] Using default backend 'copy'
3: I1121 15:40:13.418526 15992 cluster.cpp:448] Creating default 'local' authorizer
3: I1121 15:40:13.420406 15999 slave.cpp:262] Mesos agent started on (482)@172.17.0.7:46794
3: I1121 15:40:13.420424 15999 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/ReconciliationTest_UnknownTask_xiiDjJ/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/ReconciliationTest_UnknownTask_xiiDjJ/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/ReconciliationTest_UnknownTask_xiiDjJ/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/ReconciliationTest_UnknownTask_xiiDjJ/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/ReconciliationTest_UnknownTask_xiiDjJ/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/ReconciliationTest_UnknownTask_xiiDjJ" --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/ReconciliationTest_UnknownTask_Wvnp1z" --zk_session_timeout="10secs"
3: I1121 15:40:13.420871 15999 credentials.hpp:86] Loading credential for authentication from '/tmp/ReconciliationTest_UnknownTask_xiiDjJ/credential'
3: I1121 15:40:13.421052 15999 slave.cpp:295] Agent using credential for: test-principal
3: I1121 15:40:13.421072 15999 credentials.hpp:37] Loading credentials for authentication from '/tmp/ReconciliationTest_UnknownTask_xiiDjJ/http_credentials'
3: I1121 15:40:13.421314 15999 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1121 15:40:13.421471 15999 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1121 15:40:13.422873 15999 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: I1121 15:40:13.423090 15999 slave.cpp:601] Agent attributes: [ ]
3: I1121 15:40:13.423100 15999 slave.cpp:610] Agent hostname: 1c0e8cf637bb
3: I1121 15:40:13.423236 16009 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1121 15:40:13.424713 16014 state.cpp:64] Recovering state from '/tmp/ReconciliationTest_UnknownTask_Wvnp1z/meta'
3: I1121 15:40:13.424952 15998 task_status_update_manager.cpp:207] Recovering task status update manager
3: I1121 15:40:13.425109 16001 containerizer.cpp:668] Recovering containerizer
3: I1121 15:40:13.426393 15995 provisioner.cpp:455] Provisioner recovery complete
3: I1121 15:40:13.426750 16009 slave.cpp:6443] Finished recovery
3: I1121 15:40:13.427428 15999 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1121 15:40:13.427433 16000 slave.cpp:1007] New master detected at master@172.17.0.7:46794
3: I1121 15:40:13.427522 16000 slave.cpp:1042] Detecting new master
3: I1121 15:40:13.437883 16013 slave.cpp:1069] Authenticating with master master@172.17.0.7:46794
3: I1121 15:40:13.438004 16013 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1121 15:40:13.438288 15993 authenticatee.cpp:121] Creating new client SASL connection
3: I1121 15:40:13.438567 15998 master.cpp:8306] Authenticating slave(482)@172.17.0.7:46794
3: I1121 15:40:13.438663 16010 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(986)@172.17.0.7:46794
3: I1121 15:40:13.438897 16008 authenticator.cpp:98] Creating new server SASL connection
3: I1121 15:40:13.439110 15996 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1121 15:40:13.439131 15996 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1121 15:40:13.439246 16005 authenticator.cpp:204] Received SASL authentication start
3: I1121 15:40:13.439293 16005 authenticator.cpp:326] Authentication requires more steps
3: I1121 15:40:13.439388 16005 authenticatee.cpp:259] Received SASL authentication step
3: I1121 15:40:13.439507 16012 authenticator.cpp:232] Received SASL authentication step
3: I1121 15:40:13.439530 16012 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '1c0e8cf637bb' server FQDN: '1c0e8cf637bb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1121 15:40:13.439545 16012 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1121 15:40:13.439565 16012 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1121 15:40:13.439577 16012 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '1c0e8cf637bb' server FQDN: '1c0e8cf637bb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1121 15:40:13.439587 16012 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1121 15:40:13.439592 16012 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1121 15:40:13.439610 16012 authenticator.cpp:318] Authentication success
3: I1121 15:40:13.439674 16004 authenticatee.cpp:299] Authentication success
3: I1121 15:40:13.439733 16001 master.cpp:8336] Successfully authenticated principal 'test-principal' at slave(482)@172.17.0.7:46794
3: I1121 15:40:13.439777 16002 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(986)@172.17.0.7:46794
3: I1121 15:40:13.439891 16012 slave.cpp:1161] Successfully authenticated with master master@172.17.0.7:46794
3: I1121 15:40:13.440069 16012 slave.cpp:1682] Will retry registration in 9.581062ms if necessary
3: I1121 15:40:13.440285 15994 master.cpp:6036] Received register agent message from slave(482)@172.17.0.7:46794 (1c0e8cf637bb)
3: I1121 15:40:13.440418 15994 master.cpp:3872] Authorizing agent with principal 'test-principal'
3: I1121 15:40:13.440793 16011 master.cpp:6098] Authorized registration of agent at slave(482)@172.17.0.7:46794 (1c0e8cf637bb)
3: I1121 15:40:13.440904 16011 master.cpp:6191] Registering agent at slave(482)@172.17.0.7:46794 (1c0e8cf637bb) with id 665300a2-2fb6-4dbc-ad91-7c354a208f2b-S0
3: I1121 15:40:13.441311 16003 registrar.cpp:495] Applied 1 operations in 52104ns; attempting to update the registry
3: I1121 15:40:13.441798 16003 registrar.cpp:552] Successfully updated the registry in 435968ns
3: I1121 15:40:13.441995 15993 master.cpp:6240] Admitted agent 665300a2-2fb6-4dbc-ad91-7c354a208f2b-S0 at slave(482)@172.17.0.7:46794 (1c0e8cf637bb)
3: I1121 15:40:13.442575 15993 master.cpp:6273] Registered agent 665300a2-2fb6-4dbc-ad91-7c354a208f2b-S0 at slave(482)@172.17.0.7:46794 (1c0e8cf637bb) 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: I1121 15:40:13.442832 16010 slave.cpp:1207] Registered with master master@172.17.0.7:46794; given agent ID 665300a2-2fb6-4dbc-ad91-7c354a208f2b-S0
3: I1121 15:40:13.442859 15998 hierarchical.cpp:600] Added agent 665300a2-2fb6-4dbc-ad91-7c354a208f2b-S0 (1c0e8cf637bb) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
3: I1121 15:40:13.442950 16007 task_status_update_manager.cpp:188] Resuming sending task status updates
3: I1121 15:40:13.443136 16010 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/ReconciliationTest_UnknownTask_Wvnp1z/meta/slaves/665300a2-2fb6-4dbc-ad91-7c354a208f2b-S0/slave.info'
3: I1121 15:40:13.443146 15998 hierarchical.cpp:1457] Performed allocation for 1 agents in 135142ns
3: W1121 15:40:13.443416 15992 process.cpp:2756] Attempted to spawn already running process version@172.17.0.7:46794
3: I1121 15:40:13.443487 16010 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: I1121 15:40:13.443672 16006 master.cpp:7085] Received update of agent 665300a2-2fb6-4dbc-ad91-7c354a208f2b-S0 at slave(482)@172.17.0.7:46794 (1c0e8cf637bb) with total oversubscribed resources {}
3: I1121 15:40:13.443856 16006 master.cpp:7103] Ignoring update on agent 665300a2-2fb6-4dbc-ad91-7c354a208f2b-S0 at slave(482)@172.17.0.7:46794 (1c0e8cf637bb) as it reports no changes
3: I1121 15:40:13.444211 15992 sched.cpp:232] Version: 1.5.0
3: I1121 15:40:13.444665 16011 sched.cpp:336] New master detected at master@172.17.0.7:46794
3: I1121 15:40:13.444743 16011 sched.cpp:396] Authenticating with master master@172.17.0.7:46794
3: I1121 15:40:13.444759 16011 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1121 15:40:13.444993 16000 authenticatee.cpp:121] Creating new client SASL connection
3: I1121 15:40:13.445215 15999 master.cpp:8306] Authenticating scheduler-51cb4237-242d-4e89-b4aa-02ac927548ea@172.17.0.7:46794
3: I1121 15:40:13.445305 16013 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(987)@172.17.0.7:46794
3: I1121 15:40:13.445513 16003 authenticator.cpp:98] Creating new server SASL connection
3: I1121 15:40:13.445730 16008 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1121 15:40:13.445756 16008 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1121 15:40:13.445843 16008 authenticator.cpp:204] Received SASL authentication start
3: I1121 15:40:13.445889 16008 authenticator.cpp:326] Authentication requires more steps
3: I1121 15:40:13.446008 15993 authenticatee.cpp:259] Received SASL authentication step
3: I1121 15:40:13.446112 16004 authenticator.cpp:232] Received SASL authentication step
3: I1121 15:40:13.446133 16004 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '1c0e8cf637bb' server FQDN: '1c0e8cf637bb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1121 15:40:13.446142 16004 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1121 15:40:13.446159 16004 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1121 15:40:13.446173 16004 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '1c0e8cf637bb' server FQDN: '1c0e8cf637bb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1121 15:40:13.446182 16004 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1121 15:40:13.446185 16004 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1121 15:40:13.446194 16004 authenticator.cpp:318] Authentication success
3: I1121 15:40:13.446288 16015 authenticatee.cpp:299] Authentication success
3: I1121 15:40:13.446326 16001 master.cpp:8336] Successfully authenticated principal 'test-principal' at scheduler-51cb4237-242d-4e89-b4aa-02ac927548ea@172.17.0.7:46794
3: I1121 15:40:13.446358 16007 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(987)@172.17.0.7:46794
3: I1121 15:40:13.446519 16005 sched.cpp:502] Successfully authenticated with master master@172.17.0.7:46794
3: I1121 15:40:13.446533 16005 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.7:46794
3: I1121 15:40:13.446630 16005 sched.cpp:857] Will retry registration in 875.531476ms if necessary
3: I1121 15:40:13.446758 15995 master.cpp:2963] Received SUBSCRIBE call for framework 'default' at scheduler-51cb4237-242d-4e89-b4aa-02ac927548ea@172.17.0.7:46794
3: I1121 15:40:13.446830 15995 master.cpp:2280] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
3: I1121 15:40:13.447269 15997 master.cpp:3043] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1121 15:40:13.447737 16009 sched.cpp:751] Framework registered with 665300a2-2fb6-4dbc-ad91-7c354a208f2b-0000
3: I1121 15:40:13.447809 16012 hierarchical.cpp:306] Added framework 665300a2-2fb6-4dbc-ad91-7c354a208f2b-0000
3: I1121 15:40:13.447810 16009 sched.cpp:765] Scheduler::registered took 48931ns
3: I1121 15:40:13.448452 16008 master.cpp:7790] Performing explicit task state reconciliation for 1 tasks of framework 665300a2-2fb6-4dbc-ad91-7c354a208f2b-0000 (default) at scheduler-51cb4237-242d-4e89-b4aa-02ac927548ea@172.17.0.7:46794
3: I1121 15:40:13.448523 16008 master.cpp:7938] Sending explicit reconciliation state TASK_LOST for task 13ec68d2-f848-4c77-9bfd-afb482f3b533 of framework 665300a2-2fb6-4dbc-ad91-7c354a208f2b-0000 (default) at scheduler-51cb4237-242d-4e89-b4aa-02ac927548ea@172.17.0.7:46794
3: I1121 15:40:13.448789 16004 sched.cpp:1029] Scheduler::statusUpdate took 61087ns
3: I1121 15:40:13.448832 16012 hierarchical.cpp:1457] Performed allocation for 1 agents in 889032ns
3: I1121 15:40:13.448998 15992 sched.cpp:2009] Asked to stop the driver
3: I1121 15:40:13.449055 16007 sched.cpp:1191] Stopping framework 665300a2-2fb6-4dbc-ad91-7c354a208f2b-0000
3: I1121 15:40:13.449249 16001 master.cpp:8136] Sending 1 offers to framework 665300a2-2fb6-4dbc-ad91-7c354a208f2b-0000 (default) at scheduler-51cb4237-242d-4e89-b4aa-02ac927548ea@172.17.0.7:46794
3: I1121 15:40:13.449425 16001 master.cpp:8813] Processing TEARDOWN call for framework 665300a2-2fb6-4dbc-ad91-7c354a208f2b-0000 (default) at scheduler-51cb4237-242d-4e89-b4aa-02ac927548ea@172.17.0.7:46794
3: I1121 15:40:13.449447 16001 master.cpp:8825] Removing framework 665300a2-2fb6-4dbc-ad91-7c354a208f2b-0000 (default) at scheduler-51cb4237-242d-4e89-b4aa-02ac927548ea@172.17.0.7:46794
3: I1121 15:40:13.449458 16001 master.cpp:3333] Deactivating framework 665300a2-2fb6-4dbc-ad91-7c354a208f2b-0000 (default) at scheduler-51cb4237-242d-4e89-b4aa-02ac927548ea@172.17.0.7:46794
3: I1121 15:40:13.449538 16002 hierarchical.cpp:419] Deactivated framework 665300a2-2fb6-4dbc-ad91-7c354a208f2b-0000
3: I1121 15:40:13.449890 16001 master.cpp:10045] Removing offer 665300a2-2fb6-4dbc-ad91-7c354a208f2b-O0
3: I1121 15:40:13.450067 15996 slave.cpp:3267] Asked to shut down framework 665300a2-2fb6-4dbc-ad91-7c354a208f2b-0000 by master@172.17.0.7:46794
3: I1121 15:40:13.450095 15996 slave.cpp:3282] Cannot shut down unknown framework 665300a2-2fb6-4dbc-ad91-7c354a208f2b-0000
3: I1121 15:40:13.450341 16011 hierarchical.cpp:1132] 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 665300a2-2fb6-4dbc-ad91-7c354a208f2b-S0 from framework 665300a2-2fb6-4dbc-ad91-7c354a208f2b-0000
3: I1121 15:40:13.450533 15994 slave.cpp:883] Agent terminating
3: I1121 15:40:13.450562 16011 hierarchical.cpp:358] Removed framework 665300a2-2fb6-4dbc-ad91-7c354a208f2b-0000
3: I1121 15:40:13.450675 16014 master.cpp:1311] Agent 665300a2-2fb6-4dbc-ad91-7c354a208f2b-S0 at slave(482)@172.17.0.7:46794 (1c0e8cf637bb) disconnected
3: I1121 15:40:13.450693 16014 master.cpp:3370] Disconnecting agent 665300a2-2fb6-4dbc-ad91-7c354a208f2b-S0 at slave(482)@172.17.0.7:46794 (1c0e8cf637bb)
3: I1121 15:40:13.450731 16014 master.cpp:3389] Deactivating agent 665300a2-2fb6-4dbc-ad91-7c354a208f2b-S0 at slave(482)@172.17.0.7:46794 (1c0e8cf637bb)
3: I1121 15:40:13.450826 15993 hierarchical.cpp:697] Agent 665300a2-2fb6-4dbc-ad91-7c354a208f2b-S0 deactivated
3: I1121 15:40:13.455073 16007 master.cpp:1153] Master terminating
3: I1121 15:40:13.455535 16003 hierarchical.cpp:633] Removed agent 665300a2-2fb6-4dbc-ad91-7c354a208f2b-S0
3: [ OK ] ReconciliationTest.UnknownTask (56 ms)
3: [ RUN ] ReconciliationTest.UnknownTaskPartitionAware
3: I1121 15:40:13.461365 15992 cluster.cpp:162] Creating default 'local' authorizer
3: I1121 15:40:13.464570 16004 master.cpp:448] Master 8e21e98f-93bd-4fe6-bff4-a64627688205 (1c0e8cf637bb) started on 172.17.0.7:46794
3: I1121 15:40:13.464592 16004 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/xqQvpb/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/xqQvpb/master" --zk_session_timeout="10secs"
3: I1121 15:40:13.464843 16004 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1121 15:40:13.464853 16004 master.cpp:505] Master only allowing authenticated agents to register
3: I1121 15:40:13.464856 16004 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1121 15:40:13.464861 16004 credentials.hpp:37] Loading credentials for authentication from '/tmp/xqQvpb/credentials'
3: I1121 15:40:13.465097 16004 master.cpp:555] Using default 'crammd5' authenticator
3: I1121 15:40:13.465251 16004 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1121 15:40:13.465380 16004 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1121 15:40:13.465523 16004 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1121 15:40:13.465647 16004 master.cpp:634] Authorization enabled
3: I1121 15:40:13.465796 15995 whitelist_watcher.cpp:77] No whitelist given
3: I1121 15:40:13.465818 16005 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1121 15:40:13.468367 16010 master.cpp:2215] Elected as the leading master!
3: I1121 15:40:13.468389 16010 master.cpp:1695] Recovering from registrar
3: I1121 15:40:13.468495 15998 registrar.cpp:347] Recovering registrar
3: I1121 15:40:13.468953 15998 registrar.cpp:391] Successfully fetched the registry (0B) in 429824ns
3: I1121 15:40:13.469030 15998 registrar.cpp:495] Applied 1 operations in 20634ns; attempting to update the registry
3: I1121 15:40:13.469491 15998 registrar.cpp:552] Successfully updated the registry in 423936ns
3: I1121 15:40:13.469583 15998 registrar.cpp:424] Successfully recovered registrar
3: I1121 15:40:13.469892 16013 master.cpp:1808] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1121 15:40:13.469921 15996 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: W1121 15:40:13.474187 15992 process.cpp:2756] Attempted to spawn already running process files@172.17.0.7:46794
3: I1121 15:40:13.475080 15992 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1121 15:40:13.475579 15992 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1121 15:40:13.475685 15992 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1121 15:40:13.475714 15992 provisioner.cpp:259] Using default backend 'copy'
3: I1121 15:40:13.477524 15992 cluster.cpp:448] Creating default 'local' authorizer
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1511276808-12820
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers,GLOG_v=1 MESOS_VERBOSE=1,centos:7,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4486
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4486/display/redirect?page=changes>