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/13 10:59:11 UTC

Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4447

See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4447/display/redirect?page=changes>

Changes:

[alexr] Expanded description of the --recovery_timeout flag.

------------------------------------------
[...truncated 21.08 MB...]
3: I1113 10:58:57.850062 19961 master.cpp:3388] Deactivating agent dcfb559e-18bd-4a80-aa1f-c2476b017464-S0 at slave(538)@172.17.0.9:38016 (c076b2a5d6a9)
3: I1113 10:58:57.850168 19969 hierarchical.cpp:690] Agent dcfb559e-18bd-4a80-aa1f-c2476b017464-S0 deactivated
3: I1113 10:58:57.853948 19967 hierarchical.cpp:1450] Performed allocation for 1 agents in 91740ns
3: I1113 10:58:57.856822 19946 master.cpp:1151] Master terminating
3: I1113 10:58:57.857384 19956 hierarchical.cpp:626] Removed agent dcfb559e-18bd-4a80-aa1f-c2476b017464-S0
3: [       OK ] ReservationTest.BadACLDropReserve (74 ms)
3: [ RUN      ] ReservationTest.BadACLDropUnreserve
3: I1113 10:58:57.863582 19946 cluster.cpp:162] Creating default 'local' authorizer
3: I1113 10:58:57.866780 19970 master.cpp:448] Master b7b436db-d48d-466c-8ede-e57a968c253f (c076b2a5d6a9) started on 172.17.0.9:38016
3: I1113 10:58:57.866802 19970 master.cpp:450] Flags at startup: --acls="reserve_resources {
3:   principals {
3:     values: "test-principal"
3:   }
3:   roles {
3:     type: ANY
3:   }
3: }
3: unreserve_resources {
3:   principals {
3:     values: "test-principal"
3:   }
3:   reserver_principals {
3:     type: NONE
3:   }
3: }
3: " --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="5ms" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/tqaDDf/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_unreachable_tasks_per_framework="1000" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --roles="role" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/tqaDDf/master" --zk_session_timeout="10secs"
3: I1113 10:58:57.867247 19970 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1113 10:58:57.867254 19970 master.cpp:505] Master only allowing authenticated agents to register
3: I1113 10:58:57.867264 19970 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1113 10:58:57.867269 19970 credentials.hpp:37] Loading credentials for authentication from '/tmp/tqaDDf/credentials'
3: I1113 10:58:57.867590 19970 master.cpp:555] Using default 'crammd5' authenticator
3: I1113 10:58:57.867738 19970 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1113 10:58:57.867888 19970 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1113 10:58:57.868005 19970 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1113 10:58:57.868118 19970 master.cpp:634] Authorization enabled
3: W1113 10:58:57.868131 19970 master.cpp:697] The '--roles' flag is deprecated. This flag will be removed in the future. See the Mesos 0.27 upgrade notes for more information
3: I1113 10:58:57.868347 19958 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1113 10:58:57.868386 19953 whitelist_watcher.cpp:77] No whitelist given
3: I1113 10:58:57.872069 19947 master.cpp:2213] Elected as the leading master!
3: I1113 10:58:57.872099 19947 master.cpp:1693] Recovering from registrar
3: I1113 10:58:57.872308 19965 registrar.cpp:347] Recovering registrar
3: I1113 10:58:57.872799 19965 registrar.cpp:391] Successfully fetched the registry (0B) in 448us
3: I1113 10:58:57.872891 19965 registrar.cpp:495] Applied 1 operations in 21780ns; attempting to update the registry
3: I1113 10:58:57.873395 19965 registrar.cpp:552] Successfully updated the registry in 461824ns
3: I1113 10:58:57.873497 19965 registrar.cpp:424] Successfully recovered registrar
3: I1113 10:58:57.873893 19962 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1113 10:58:57.873905 19965 hierarchical.cpp:1450] Performed allocation for 0 agents in 32951ns
3: I1113 10:58:57.874109 19965 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: W1113 10:58:57.880183 19946 process.cpp:3178] Attempted to spawn already running process files@172.17.0.9:38016
3: I1113 10:58:57.881466 19946 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: I1113 10:58:57.881678 19949 hierarchical.cpp:1450] Performed allocation for 0 agents in 48244ns
3: W1113 10:58:57.882071 19946 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1113 10:58:57.882221 19946 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1113 10:58:57.882249 19946 provisioner.cpp:255] Using default backend 'copy'
3: I1113 10:58:57.884970 19946 cluster.cpp:448] Creating default 'local' authorizer
3: I1113 10:58:57.887364 19965 slave.cpp:262] Mesos agent started on (539)@172.17.0.9:38016
3: I1113 10:58:57.887382 19965 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/ReservationTest_BadACLDropUnreserve_5rdgKH/store/appc" --authenticate_http_executors="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/ReservationTest_BadACLDropUnreserve_5rdgKH/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/ReservationTest_BadACLDropUnreserve_5rdgKH/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_secret_key="/tmp/ReservationTest_BadACLDropUnreserve_5rdgKH/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ReservationTest_BadACLDropUnreserve_5rdgKH/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/ReservationTest_BadACLDropUnreserve_5rdgKH/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" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/ReservationTest_BadACLDropUnreserve_5rdgKH" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/ReservationTest_BadACLDropUnreserve_nE8VGt" --zk_session_timeout="10secs"
3: I1113 10:58:57.887828 19965 credentials.hpp:86] Loading credential for authentication from '/tmp/ReservationTest_BadACLDropUnreserve_5rdgKH/credential'
3: I1113 10:58:57.887979 19965 slave.cpp:295] Agent using credential for: test-principal
3: I1113 10:58:57.887995 19965 credentials.hpp:37] Loading credentials for authentication from '/tmp/ReservationTest_BadACLDropUnreserve_5rdgKH/http_credentials'
3: W1113 10:58:57.887992 19946 process.cpp:3178] Attempted to spawn already running process version@172.17.0.9:38016
3: I1113 10:58:57.888280 19965 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1113 10:58:57.888396 19965 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1113 10:58:57.888578 19965 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1113 10:58:57.888669 19965 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1113 10:58:57.888839 19965 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1113 10:58:57.888934 19965 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1113 10:58:57.889189 19946 sched.cpp:232] Version: 1.5.0
3: I1113 10:58:57.889693 19967 sched.cpp:336] New master detected at master@172.17.0.9:38016
3: I1113 10:58:57.889781 19967 sched.cpp:396] Authenticating with master master@172.17.0.9:38016
3: I1113 10:58:57.889796 19967 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1113 10:58:57.890044 19964 authenticatee.cpp:121] Creating new client SASL connection
3: I1113 10:58:57.890244 19949 hierarchical.cpp:1450] Performed allocation for 0 agents in 35115ns
3: I1113 10:58:57.890005 19965 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":367489.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1113 10:58:57.890311 19965 slave.cpp:601] Agent attributes: [  ]
3: I1113 10:58:57.890321 19965 slave.cpp:610] Agent hostname: c076b2a5d6a9
3: I1113 10:58:57.890321 19960 master.cpp:8286] Authenticating scheduler-cd977e26-ad1f-49cd-a828-65ca6677a26a@172.17.0.9:38016
3: I1113 10:58:57.890422 19949 status_update_manager.cpp:177] Pausing sending status updates
3: I1113 10:58:57.890456 19949 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1085)@172.17.0.9:38016
3: I1113 10:58:57.890647 19951 authenticator.cpp:98] Creating new server SASL connection
3: I1113 10:58:57.890841 19966 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1113 10:58:57.890877 19966 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1113 10:58:57.890990 19966 authenticator.cpp:204] Received SASL authentication start
3: I1113 10:58:57.891047 19966 authenticator.cpp:326] Authentication requires more steps
3: I1113 10:58:57.891124 19969 authenticatee.cpp:259] Received SASL authentication step
3: I1113 10:58:57.891249 19961 authenticator.cpp:232] Received SASL authentication step
3: I1113 10:58:57.891284 19961 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'c076b2a5d6a9' server FQDN: 'c076b2a5d6a9' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1113 10:58:57.891295 19961 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1113 10:58:57.891324 19961 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1113 10:58:57.891340 19961 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'c076b2a5d6a9' server FQDN: 'c076b2a5d6a9' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1113 10:58:57.891350 19961 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1113 10:58:57.891355 19961 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1113 10:58:57.891367 19961 authenticator.cpp:318] Authentication success
3: I1113 10:58:57.891460 19963 authenticatee.cpp:299] Authentication success
3: I1113 10:58:57.891564 19962 master.cpp:8316] Successfully authenticated principal 'test-principal' at scheduler-cd977e26-ad1f-49cd-a828-65ca6677a26a@172.17.0.9:38016
3: I1113 10:58:57.891597 19963 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1085)@172.17.0.9:38016
3: I1113 10:58:57.891860 19955 state.cpp:64] Recovering state from '/tmp/ReservationTest_BadACLDropUnreserve_nE8VGt/meta'
3: I1113 10:58:57.892012 19952 sched.cpp:502] Successfully authenticated with master master@172.17.0.9:38016
3: I1113 10:58:57.892058 19952 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.9:38016
3: I1113 10:58:57.892084 19959 status_update_manager.cpp:203] Recovering status update manager
3: I1113 10:58:57.892208 19952 sched.cpp:857] Will retry registration in 1.105744947secs if necessary
3: I1113 10:58:57.892295 19968 containerizer.cpp:662] Recovering containerizer
3: I1113 10:58:57.892412 19970 master.cpp:2962] Received SUBSCRIBE call for framework 'default' at scheduler-cd977e26-ad1f-49cd-a828-65ca6677a26a@172.17.0.9:38016
3: I1113 10:58:57.892490 19970 master.cpp:2278] Authorizing framework principal 'test-principal' to receive offers for roles '{ role }'
3: I1113 10:58:57.892877 19961 master.cpp:3042] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1113 10:58:57.893501 19954 sched.cpp:751] Framework registered with b7b436db-d48d-466c-8ede-e57a968c253f-0000
3: I1113 10:58:57.893553 19954 sched.cpp:765] Scheduler::registered took 27776ns
3: I1113 10:58:57.893604 19950 hierarchical.cpp:303] Added framework b7b436db-d48d-466c-8ede-e57a968c253f-0000
3: I1113 10:58:57.893699 19948 provisioner.cpp:416] Provisioner recovery complete
3: I1113 10:58:57.893808 19950 hierarchical.cpp:1450] Performed allocation for 0 agents in 73176ns
3: I1113 10:58:57.894035 19948 slave.cpp:6422] Finished recovery
3: I1113 10:58:57.894804 19951 slave.cpp:1007] New master detected at master@172.17.0.9:38016
3: I1113 10:58:57.894819 19948 status_update_manager.cpp:177] Pausing sending status updates
3: I1113 10:58:57.894865 19951 slave.cpp:1042] Detecting new master
3: I1113 10:58:57.897884 19969 hierarchical.cpp:1450] Performed allocation for 0 agents in 56646ns
3: I1113 10:58:57.902156 19949 slave.cpp:1069] Authenticating with master master@172.17.0.9:38016
3: I1113 10:58:57.902226 19949 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1113 10:58:57.902564 19947 authenticatee.cpp:121] Creating new client SASL connection
3: I1113 10:58:57.902979 19960 master.cpp:8286] Authenticating slave(539)@172.17.0.9:38016
3: I1113 10:58:57.903133 19968 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1086)@172.17.0.9:38016
3: I1113 10:58:57.903396 19957 authenticator.cpp:98] Creating new server SASL connection
3: I1113 10:58:57.903734 19953 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1113 10:58:57.903789 19953 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1113 10:58:57.903947 19963 authenticator.cpp:204] Received SASL authentication start
3: I1113 10:58:57.904013 19963 authenticator.cpp:326] Authentication requires more steps
3: I1113 10:58:57.904126 19961 authenticatee.cpp:259] Received SASL authentication step
3: I1113 10:58:57.904250 19958 authenticator.cpp:232] Received SASL authentication step
3: I1113 10:58:57.904289 19958 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'c076b2a5d6a9' server FQDN: 'c076b2a5d6a9' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1113 10:58:57.904304 19958 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1113 10:58:57.904325 19958 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1113 10:58:57.904350 19958 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'c076b2a5d6a9' server FQDN: 'c076b2a5d6a9' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1113 10:58:57.904361 19958 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1113 10:58:57.904366 19958 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1113 10:58:57.904378 19958 authenticator.cpp:318] Authentication success
3: I1113 10:58:57.904495 19954 authenticatee.cpp:299] Authentication success
3: I1113 10:58:57.904511 19965 master.cpp:8316] Successfully authenticated principal 'test-principal' at slave(539)@172.17.0.9:38016
3: I1113 10:58:57.904556 19962 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1086)@172.17.0.9:38016
3: I1113 10:58:57.904757 19950 slave.cpp:1161] Successfully authenticated with master master@172.17.0.9:38016
3: I1113 10:58:57.904996 19950 slave.cpp:1682] Will retry registration in 15.946724ms if necessary
3: I1113 10:58:57.905303 19952 master.cpp:6033] Received register agent message from slave(539)@172.17.0.9:38016 (c076b2a5d6a9)
3: I1113 10:58:57.905467 19952 master.cpp:3871] Authorizing agent with principal 'test-principal'
3: I1113 10:58:57.905894 19964 master.cpp:6093] Authorized registration of agent at slave(539)@172.17.0.9:38016 (c076b2a5d6a9)
3: I1113 10:58:57.905977 19964 master.cpp:6186] Registering agent at slave(539)@172.17.0.9:38016 (c076b2a5d6a9) with id b7b436db-d48d-466c-8ede-e57a968c253f-S0
3: I1113 10:58:57.906342 19948 registrar.cpp:495] Applied 1 operations in 56869ns; attempting to update the registry
3: I1113 10:58:57.906388 19970 hierarchical.cpp:1450] Performed allocation for 0 agents in 50979ns
3: I1113 10:58:57.906847 19948 registrar.cpp:552] Successfully updated the registry in 456960ns
3: I1113 10:58:57.907145 19947 master.cpp:6233] Admitted agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 at slave(539)@172.17.0.9:38016 (c076b2a5d6a9)
3: I1113 10:58:57.908025 19947 master.cpp:6264] Registered agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 at slave(539)@172.17.0.9:38016 (c076b2a5d6a9) with [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":367489.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1113 10:58:57.908228 19968 slave.cpp:1207] Registered with master master@172.17.0.9:38016; given agent ID b7b436db-d48d-466c-8ede-e57a968c253f-S0
3: I1113 10:58:57.908315 19960 hierarchical.cpp:593] Added agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 (c076b2a5d6a9) with cpus:2; mem:1024; disk:367489; ports:[31000-32000] (allocated: {})
3: I1113 10:58:57.908370 19963 status_update_manager.cpp:184] Resuming sending status updates
3: I1113 10:58:57.908605 19968 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/ReservationTest_BadACLDropUnreserve_nE8VGt/meta/slaves/b7b436db-d48d-466c-8ede-e57a968c253f-S0/slave.info'
3: I1113 10:58:57.908993 19968 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: I1113 10:58:57.909240 19968 master.cpp:7065] Received update of agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 at slave(539)@172.17.0.9:38016 (c076b2a5d6a9) with total oversubscribed resources {}
3: I1113 10:58:57.909503 19968 master.cpp:7083] Ignoring update on agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 at slave(539)@172.17.0.9:38016 (c076b2a5d6a9) as it reports no changes
3: I1113 10:58:57.909799 19960 hierarchical.cpp:1450] Performed allocation for 1 agents in 1.328428ms
3: I1113 10:58:57.910336 19958 master.cpp:8116] Sending 1 offers to framework b7b436db-d48d-466c-8ede-e57a968c253f-0000 (default) at scheduler-cd977e26-ad1f-49cd-a828-65ca6677a26a@172.17.0.9:38016
3: I1113 10:58:57.910812 19954 sched.cpp:921] Scheduler::resourceOffers took 96575ns
3: I1113 10:58:57.912334 19966 master.cpp:10016] Removing offer b7b436db-d48d-466c-8ede-e57a968c253f-O0
3: I1113 10:58:57.912482 19966 master.cpp:4229] Processing ACCEPT call for offers: [ b7b436db-d48d-466c-8ede-e57a968c253f-O0 ] on agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 at slave(539)@172.17.0.9:38016 (c076b2a5d6a9) for framework b7b436db-d48d-466c-8ede-e57a968c253f-0000 (default) at scheduler-cd977e26-ad1f-49cd-a828-65ca6677a26a@172.17.0.9:38016
3: I1113 10:58:57.912653 19966 master.cpp:3656] Authorizing principal 'test-principal' to reserve resources '[{"allocation_info":{"role":"role"},"name":"cpus","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"role"},"name":"mem","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":512.0},"type":"SCALAR"}]'
3: I1113 10:58:57.914067 19948 hierarchical.cpp:1450] Performed allocation for 1 agents in 116589ns
3: I1113 10:58:57.914337 19949 master.cpp:4562] Applying RESERVE operation for resources [{"allocation_info":{"role":"role"},"name":"cpus","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"role"},"name":"mem","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":512.0},"type":"SCALAR"}] from framework b7b436db-d48d-466c-8ede-e57a968c253f-0000 (default) at scheduler-cd977e26-ad1f-49cd-a828-65ca6677a26a@172.17.0.9:38016 to agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 at slave(539)@172.17.0.9:38016 (c076b2a5d6a9)
3: I1113 10:58:57.915038 19949 master.cpp:9961] Sending updated checkpointed resources cpus(reservations: [(DYNAMIC,role,test-principal)]):1; mem(reservations: [(DYNAMIC,role,test-principal)]):512 to agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 at slave(539)@172.17.0.9:38016 (c076b2a5d6a9)
3: I1113 10:58:57.915910 19957 slave.cpp:3587] Updated checkpointed resources from {} to cpus(reservations: [(DYNAMIC,role,test-principal)]):1; mem(reservations: [(DYNAMIC,role,test-principal)]):512
3: I1113 10:58:57.918336 19953 hierarchical.cpp:849] Updated allocation of framework b7b436db-d48d-466c-8ede-e57a968c253f-0000 on agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 from cpus(allocated: role):2; mem(allocated: role):1024; disk(allocated: role):367489; ports(allocated: role):[31000-32000] to cpus(allocated: role):1; mem(allocated: role):512; disk(allocated: role):367489; ports(allocated: role):[31000-32000]; cpus(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):1; mem(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):512
3: I1113 10:58:57.919909 19953 hierarchical.cpp:1125] Recovered cpus(allocated: role):1; mem(allocated: role):512; disk(allocated: role):367489; ports(allocated: role):[31000-32000]; cpus(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):1; mem(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):512 (total: cpus:1; mem:512; disk:367489; ports:[31000-32000]; cpus(reservations: [(DYNAMIC,role,test-principal)]):1; mem(reservations: [(DYNAMIC,role,test-principal)]):512, allocated: {}) on agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 from framework b7b436db-d48d-466c-8ede-e57a968c253f-0000
3: I1113 10:58:57.923157 19947 hierarchical.cpp:1450] Performed allocation for 1 agents in 1.46706ms
3: I1113 10:58:57.923852 19963 master.cpp:8116] Sending 1 offers to framework b7b436db-d48d-466c-8ede-e57a968c253f-0000 (default) at scheduler-cd977e26-ad1f-49cd-a828-65ca6677a26a@172.17.0.9:38016
3: I1113 10:58:57.924362 19963 sched.cpp:921] Scheduler::resourceOffers took 105134ns
3: I1113 10:58:57.926618 19965 master.cpp:10016] Removing offer b7b436db-d48d-466c-8ede-e57a968c253f-O1
3: I1113 10:58:57.926762 19965 master.cpp:4229] Processing ACCEPT call for offers: [ b7b436db-d48d-466c-8ede-e57a968c253f-O1 ] on agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 at slave(539)@172.17.0.9:38016 (c076b2a5d6a9) for framework b7b436db-d48d-466c-8ede-e57a968c253f-0000 (default) at scheduler-cd977e26-ad1f-49cd-a828-65ca6677a26a@172.17.0.9:38016
3: I1113 10:58:57.926923 19965 master.cpp:3724] Authorizing principal 'test-principal' to unreserve resources '[{"allocation_info":{"role":"role"},"name":"cpus","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"role"},"name":"mem","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":512.0},"type":"SCALAR"}]'
3: I1113 10:58:57.927363 19965 master.cpp:3656] Authorizing principal 'test-principal' to reserve resources '[{"allocation_info":{"role":"role"},"name":"cpus","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":0.5},"type":"SCALAR"},{"allocation_info":{"role":"role"},"name":"mem","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":256.0},"type":"SCALAR"}]'
3: W1113 10:58:57.928288 19970 master.cpp:2363] Dropping UNRESERVE offer operation from framework b7b436db-d48d-466c-8ede-e57a968c253f-0000 (default) at scheduler-cd977e26-ad1f-49cd-a828-65ca6677a26a@172.17.0.9:38016: Not authorized to unreserve resources as 'test-principal'
3: I1113 10:58:57.929337 19970 master.cpp:4562] Applying RESERVE operation for resources [{"allocation_info":{"role":"role"},"name":"cpus","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":0.5},"type":"SCALAR"},{"allocation_info":{"role":"role"},"name":"mem","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":256.0},"type":"SCALAR"}] from framework b7b436db-d48d-466c-8ede-e57a968c253f-0000 (default) at scheduler-cd977e26-ad1f-49cd-a828-65ca6677a26a@172.17.0.9:38016 to agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 at slave(539)@172.17.0.9:38016 (c076b2a5d6a9)
3: I1113 10:58:57.929765 19948 hierarchical.cpp:1450] Performed allocation for 1 agents in 140667ns
3: I1113 10:58:57.930162 19970 master.cpp:9961] Sending updated checkpointed resources cpus(reservations: [(DYNAMIC,role,test-principal)]):1.5; mem(reservations: [(DYNAMIC,role,test-principal)]):768 to agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 at slave(539)@172.17.0.9:38016 (c076b2a5d6a9)
3: I1113 10:58:57.931053 19949 slave.cpp:3587] Updated checkpointed resources from cpus(reservations: [(DYNAMIC,role,test-principal)]):1; mem(reservations: [(DYNAMIC,role,test-principal)]):512 to cpus(reservations: [(DYNAMIC,role,test-principal)]):1.5; mem(reservations: [(DYNAMIC,role,test-principal)]):768
3: I1113 10:58:57.933995 19957 hierarchical.cpp:849] Updated allocation of framework b7b436db-d48d-466c-8ede-e57a968c253f-0000 on agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 from cpus(allocated: role):1; mem(allocated: role):512; disk(allocated: role):367489; ports(allocated: role):[31000-32000]; cpus(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):1; mem(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):512 to cpus(allocated: role):0.5; mem(allocated: role):256; disk(allocated: role):367489; ports(allocated: role):[31000-32000]; cpus(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):1.5; mem(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):768
3: I1113 10:58:57.935360 19957 hierarchical.cpp:1125] Recovered cpus(allocated: role):0.5; mem(allocated: role):256; disk(allocated: role):367489; ports(allocated: role):[31000-32000]; cpus(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):1.5; mem(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):768 (total: cpus:0.5; mem:256; disk:367489; ports:[31000-32000]; cpus(reservations: [(DYNAMIC,role,test-principal)]):1.5; mem(reservations: [(DYNAMIC,role,test-principal)]):768, allocated: {}) on agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 from framework b7b436db-d48d-466c-8ede-e57a968c253f-0000
3: I1113 10:58:57.938961 19953 hierarchical.cpp:1450] Performed allocation for 1 agents in 1.466691ms
3: I1113 10:58:57.939621 19947 master.cpp:8116] Sending 1 offers to framework b7b436db-d48d-466c-8ede-e57a968c253f-0000 (default) at scheduler-cd977e26-ad1f-49cd-a828-65ca6677a26a@172.17.0.9:38016
3: I1113 10:58:57.940129 19961 sched.cpp:921] Scheduler::resourceOffers took 105962ns
3: I1113 10:58:57.940709 19946 sched.cpp:2009] Asked to stop the driver
3: I1113 10:58:57.940901 19958 sched.cpp:1191] Stopping framework b7b436db-d48d-466c-8ede-e57a968c253f-0000
3: I1113 10:58:57.941184 19967 master.cpp:8793] Processing TEARDOWN call for framework b7b436db-d48d-466c-8ede-e57a968c253f-0000 (default) at scheduler-cd977e26-ad1f-49cd-a828-65ca6677a26a@172.17.0.9:38016
3: I1113 10:58:57.941215 19967 master.cpp:8805] Removing framework b7b436db-d48d-466c-8ede-e57a968c253f-0000 (default) at scheduler-cd977e26-ad1f-49cd-a828-65ca6677a26a@172.17.0.9:38016
3: I1113 10:58:57.941226 19967 master.cpp:3332] Deactivating framework b7b436db-d48d-466c-8ede-e57a968c253f-0000 (default) at scheduler-cd977e26-ad1f-49cd-a828-65ca6677a26a@172.17.0.9:38016
3: I1113 10:58:57.941414 19952 hierarchical.cpp:412] Deactivated framework b7b436db-d48d-466c-8ede-e57a968c253f-0000
3: I1113 10:58:57.942072 19967 master.cpp:10016] Removing offer b7b436db-d48d-466c-8ede-e57a968c253f-O2
3: I1113 10:58:57.942263 19963 slave.cpp:3267] Asked to shut down framework b7b436db-d48d-466c-8ede-e57a968c253f-0000 by master@172.17.0.9:38016
3: I1113 10:58:57.942294 19963 slave.cpp:3282] Cannot shut down unknown framework b7b436db-d48d-466c-8ede-e57a968c253f-0000
3: I1113 10:58:57.942896 19952 hierarchical.cpp:1125] Recovered cpus(allocated: role):0.5; mem(allocated: role):256; disk(allocated: role):367489; ports(allocated: role):[31000-32000]; cpus(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):1.5; mem(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):768 (total: cpus:0.5; mem:256; disk:367489; ports:[31000-32000]; cpus(reservations: [(DYNAMIC,role,test-principal)]):1.5; mem(reservations: [(DYNAMIC,role,test-principal)]):768, allocated: {}) on agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 from framework b7b436db-d48d-466c-8ede-e57a968c253f-0000
3: I1113 10:58:57.943001 19957 slave.cpp:883] Agent terminating
3: I1113 10:58:57.943205 19969 master.cpp:1309] Agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 at slave(539)@172.17.0.9:38016 (c076b2a5d6a9) disconnected
3: I1113 10:58:57.943244 19969 master.cpp:3369] Disconnecting agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 at slave(539)@172.17.0.9:38016 (c076b2a5d6a9)
3: I1113 10:58:57.943285 19969 master.cpp:3388] Deactivating agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 at slave(539)@172.17.0.9:38016 (c076b2a5d6a9)
3: I1113 10:58:57.943320 19952 hierarchical.cpp:355] Removed framework b7b436db-d48d-466c-8ede-e57a968c253f-0000
3: I1113 10:58:57.943493 19952 hierarchical.cpp:690] Agent b7b436db-d48d-466c-8ede-e57a968c253f-S0 deactivated
3: I1113 10:58:57.945557 19955 hierarchical.cpp:1450] Performed allocation for 1 agents in 133809ns
3: I1113 10:58:57.949749 19946 master.cpp:1151] Master terminating
3: I1113 10:58:57.950701 19968 hierarchical.cpp:626] Removed agent b7b436db-d48d-466c-8ede-e57a968c253f-S0
3: [       OK ] ReservationTest.BadACLDropUnreserve (93 ms)
3: [ RUN      ] ReservationTest.ACLMultipleOperations
3: I1113 10:58:57.959242 19946 cluster.cpp:162] Creating default 'local' authorizer
3: I1113 10:58:57.964246 19961 master.cpp:448] Master 5c70027f-512e-41c5-8c17-a9d637364bf0 (c076b2a5d6a9) started on 172.17.0.9:38016
3: I1113 10:58:57.964282 19961 master.cpp:450] Flags at startup: --acls="reserve_resources {
3:   principals {
3:     values: "test-principal"
3:   }
3:   roles {
3:     type: ANY
3:   }
3: }
3: unreserve_resources {
3:   principals {
3:     values: "test-principal"
3:   }
3:   reserver_principals {
3:     type: NONE
3:   }
3: }
3: " --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="5ms" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/dDL7xQ/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_unreachable_tasks_per_framework="1000" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --roles="role" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/dDL7xQ/master" --zk_session_timeout="10secs"
3: I1113 10:58:57.964774 19961 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1113 10:58:57.964784 19961 master.cpp:505] Master only allowing authenticated agents to register
3: I1113 10:58:57.964790 19961 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1113 10:58:57.964797 19961 credentials.hpp:37] Loading credentials for authentication from '/tmp/dDL7xQ/credentials'
3: I1113 10:58:57.965201 19961 master.cpp:555] Using default 'crammd5' authenticator
3: I1113 10:58:57.965381 19961 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1113 10:58:57.965623 19961 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1113 10:58:57.965790 19961 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1113 10:58:57.965952 19961 master.cpp:634] Authorization enabled
3: W1113 10:58:57.965970 19961 master.cpp:697] The '--roles' flag is deprecated. This flag will be removed in the future. See the Mesos 0.27 upgrade notes for more information
3: I1113 10:58:57.966223 19970 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1113 10:58:57.966225 19969 whitelist_watcher.cpp:77] No whitelist given
3: I1113 10:58:57.969149 19957 master.cpp:2213] Elected as the leading master!
3: I1113 10:58:57.969175 19957 master.cpp:1693] Recovering from registrar
3: I1113 10:58:57.969357 19953 registrar.cpp:347] Recovering registrar
3: I1113 10:58:57.969969 19953 registrar.cpp:391] Successfully fetched the registry (0B) in 0ns
3: I1113 10:58:57.970058 19953 registrar.cpp:495] Applied 1 operations in 24051ns; attempting to update the registry
3: I1113 10:58:57.970556 19953 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1113 10:58:57.970664 19953 registrar.cpp:424] Successfully recovered registrar
3: I1113 10:58:57.971050 19965 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1113 10:58:57.971065 19951 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1510568537-11173
Process leaked file descriptors. See https://jenkins.io/redirect/troubleshooting/process-leaked-file-descriptors for more information
Build step 'Execute shell' marked build as failure


Jenkins build is back to normal : Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4448

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4448/display/redirect?page=changes>