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/08/09 00:21:22 UTC

Build failed in Jenkins: Mesos-Buildbot » cmake,clang,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2) #4079

See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,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)/4079/display/redirect>

------------------------------------------
Started by upstream project "Mesos-Buildbot" build number 4079
originally caused by:
 Started by an SCM change
[EnvInject] - Loading node environment variables.
Building remotely on H14 (couchdbtest ubuntu xenial) in workspace <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,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)/ws/>
Wiping out workspace first.
Cloning the remote Git repository
Cloning repository https://git-wip-us.apache.org/repos/asf/mesos.git
 > git init <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,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)/ws/> # timeout=10
Fetching upstream changes from https://git-wip-us.apache.org/repos/asf/mesos.git
 > git --version # timeout=10
 > git fetch --tags --progress https://git-wip-us.apache.org/repos/asf/mesos.git +refs/heads/*:refs/remotes/origin/*
 > git config remote.origin.url https://git-wip-us.apache.org/repos/asf/mesos.git # timeout=10
 > git config --add remote.origin.fetch +refs/heads/*:refs/remotes/origin/* # timeout=10
 > git config remote.origin.url https://git-wip-us.apache.org/repos/asf/mesos.git # timeout=10
Fetching upstream changes from https://git-wip-us.apache.org/repos/asf/mesos.git
 > git fetch --tags --progress https://git-wip-us.apache.org/repos/asf/mesos.git +refs/heads/*:refs/remotes/origin/*
Checking out Revision 68dd1f6a12c321a21a7e6e257d5a23b41d127273 (refs/tags/0.27.3-rc1, refs/tags/0.27.3)
Commit message: "Updated configure.ac to 0.27.3."
 > git config core.sparsecheckout # timeout=10
 > git checkout -f 68dd1f6a12c321a21a7e6e257d5a23b41d127273
First time build. Skipping changelog.
[78e10458] $ /bin/bash -xe /tmp/jenkins5533925963937594387.sh
+ '[' refs/tags/0.27.3-rc1 = origin/1.0.x ']'
+ ./support/jenkins/buildbot.sh
/tmp/jenkins5533925963937594387.sh: line 6: ./support/jenkins/buildbot.sh: No such file or directory
Build step 'Execute shell' marked build as failure

Jenkins build is back to normal : Mesos-Buildbot » cmake,clang,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2) #4081

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,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)/4081/display/redirect>

Build failed in Jenkins: Mesos-Buildbot » cmake,clang,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2) #4080

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,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)/4080/display/redirect?page=changes>

Changes:

[mpark] Fixed `mesos-execute` help text related to task resources.

------------------------------------------
[...truncated 18.57 MB...]
I0809 01:05:00.169996   767 master.cpp:7667] Sending 1 offers to framework c6d6dd06-c5f9-4d99-8adc-0fdfb4a9d165-0000 (default) at scheduler-024a968e-6890-485b-b587-9f5fcfce9040@172.17.0.4:42552
I0809 01:05:00.170606   755 sched.cpp:933] Scheduler::resourceOffers took 107276ns
I0809 01:05:00.171032   751 sched.cpp:2021] Asked to stop the driver
I0809 01:05:00.171139   766 sched.cpp:1203] Stopping framework c6d6dd06-c5f9-4d99-8adc-0fdfb4a9d165-0000
I0809 01:05:00.171475   774 master.cpp:8348] Processing TEARDOWN call for framework c6d6dd06-c5f9-4d99-8adc-0fdfb4a9d165-0000 (default) at scheduler-024a968e-6890-485b-b587-9f5fcfce9040@172.17.0.4:42552
I0809 01:05:00.171507   774 master.cpp:8360] Removing framework c6d6dd06-c5f9-4d99-8adc-0fdfb4a9d165-0000 (default) at scheduler-024a968e-6890-485b-b587-9f5fcfce9040@172.17.0.4:42552
I0809 01:05:00.171525   774 master.cpp:3264] Deactivating framework c6d6dd06-c5f9-4d99-8adc-0fdfb4a9d165-0000 (default) at scheduler-024a968e-6890-485b-b587-9f5fcfce9040@172.17.0.4:42552
I0809 01:05:00.171694   763 hierarchical.cpp:412] Deactivated framework c6d6dd06-c5f9-4d99-8adc-0fdfb4a9d165-0000
I0809 01:05:00.172082   774 master.cpp:9164] Removing offer c6d6dd06-c5f9-4d99-8adc-0fdfb4a9d165-O4
I0809 01:05:00.172277   752 slave.cpp:3155] Asked to shut down framework c6d6dd06-c5f9-4d99-8adc-0fdfb4a9d165-0000 by master@172.17.0.4:42552
I0809 01:05:00.172303   752 slave.cpp:3170] Cannot shut down unknown framework c6d6dd06-c5f9-4d99-8adc-0fdfb4a9d165-0000
I0809 01:05:00.172672   763 hierarchical.cpp:1152] Recovered disk(allocated: role1):1024; cpus(allocated: role1):24; mem(allocated: role1):95614; ports(allocated: role1):[31000-32000] (total: disk:1024; cpus:24; mem:95614; ports:[31000-32000], allocated: {}) on agent c6d6dd06-c5f9-4d99-8adc-0fdfb4a9d165-S0 from framework c6d6dd06-c5f9-4d99-8adc-0fdfb4a9d165-0000
I0809 01:05:00.178828   757 hierarchical.cpp:355] Removed framework c6d6dd06-c5f9-4d99-8adc-0fdfb4a9d165-0000
I0809 01:05:00.179747   755 slave.cpp:843] Agent terminating
I0809 01:05:00.179988   768 master.cpp:1318] Agent c6d6dd06-c5f9-4d99-8adc-0fdfb4a9d165-S0 at slave(465)@172.17.0.4:42552 (dd9635de8477) disconnected
I0809 01:05:00.180055   768 master.cpp:3301] Disconnecting agent c6d6dd06-c5f9-4d99-8adc-0fdfb4a9d165-S0 at slave(465)@172.17.0.4:42552 (dd9635de8477)
I0809 01:05:00.180131   768 master.cpp:3320] Deactivating agent c6d6dd06-c5f9-4d99-8adc-0fdfb4a9d165-S0 at slave(465)@172.17.0.4:42552 (dd9635de8477)
I0809 01:05:00.180294   763 hierarchical.cpp:690] Agent c6d6dd06-c5f9-4d99-8adc-0fdfb4a9d165-S0 deactivated
I0809 01:05:00.187659   769 master.cpp:1160] Master terminating
I0809 01:05:00.188606   762 hierarchical.cpp:626] Removed agent c6d6dd06-c5f9-4d99-8adc-0fdfb4a9d165-S0
[       OK ] PersistentVolumeEndpointsTest.OfferCreateThenEndpointRemove (306 ms)
[ RUN      ] PersistentVolumeEndpointsTest.EndpointCreateThenOfferRemove
I0809 01:05:00.197989   751 cluster.cpp:162] Creating default 'local' authorizer
I0809 01:05:00.201673   766 master.cpp:442] Master 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165 (dd9635de8477) started on 172.17.0.4:42552
I0809 01:05:00.201721   766 master.cpp:444] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --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/A3jmf4/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="role1" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/A3jmf4/master" --zk_session_timeout="10secs"
I0809 01:05:00.202121   766 master.cpp:494] Master only allowing authenticated frameworks to register
I0809 01:05:00.202134   766 master.cpp:508] Master only allowing authenticated agents to register
I0809 01:05:00.202139   766 master.cpp:521] Master only allowing authenticated HTTP frameworks to register
I0809 01:05:00.202145   766 credentials.hpp:37] Loading credentials for authentication from '/tmp/A3jmf4/credentials'
I0809 01:05:00.202488   766 master.cpp:566] Using default 'crammd5' authenticator
I0809 01:05:00.202662   766 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0809 01:05:00.202847   766 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0809 01:05:00.203079   766 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0809 01:05:00.203202   766 master.cpp:646] Authorization enabled
W0809 01:05:00.203215   766 master.cpp:709] The '--roles' flag is deprecated. This flag will be removed in the future. See the Mesos 0.27 upgrade notes for more information
I0809 01:05:00.203408   757 hierarchical.cpp:171] Initialized hierarchical allocator process
I0809 01:05:00.203435   769 whitelist_watcher.cpp:77] No whitelist given
I0809 01:05:00.207448   756 master.cpp:2163] Elected as the leading master!
I0809 01:05:00.207482   756 master.cpp:1702] Recovering from registrar
I0809 01:05:00.207722   772 registrar.cpp:347] Recovering registrar
I0809 01:05:00.208405   772 registrar.cpp:391] Successfully fetched the registry (0B) in 646912ns
I0809 01:05:00.208530   772 registrar.cpp:495] Applied 1 operations in 45259ns; attempting to update the registry
I0809 01:05:00.209086   772 registrar.cpp:552] Successfully updated the registry in 499968ns
I0809 01:05:00.209200   772 registrar.cpp:424] Successfully recovered registrar
I0809 01:05:00.209676   758 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
I0809 01:05:00.209692   775 master.cpp:1801] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
I0809 01:05:00.216529   751 process.cpp:3228] Attempting to spawn already spawned process files@172.17.0.4:42552
I0809 01:05:00.221179   751 containerizer.cpp:246] Using isolation: posix/cpu,posix/mem,filesystem/posix,network/cni,environment_secret
W0809 01:05:00.221936   751 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0809 01:05:00.222134   751 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0809 01:05:00.222169   751 provisioner.cpp:255] Using default backend 'copy'
I0809 01:05:00.224849   751 cluster.cpp:448] Creating default 'local' authorizer
I0809 01:05:00.229107   757 slave.cpp:250] Mesos agent started on (466)@172.17.0.4:42552
I0809 01:05:00.229148   757 slave.cpp:251] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/PersistentVolumeEndpointsTest_EndpointCreateThenOfferRemove_sGwsLe/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/PersistentVolumeEndpointsTest_EndpointCreateThenOfferRemove_sGwsLe/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/PersistentVolumeEndpointsTest_EndpointCreateThenOfferRemove_sGwsLe/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/PersistentVolumeEndpointsTest_EndpointCreateThenOfferRemove_sGwsLe/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/PersistentVolumeEndpointsTest_EndpointCreateThenOfferRemove_sGwsLe/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/PersistentVolumeEndpointsTest_EndpointCreateThenOfferRemove_sGwsLe/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="disk(*):1024" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/PersistentVolumeEndpointsTest_EndpointCreateThenOfferRemove_sGwsLe" --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/PersistentVolumeEndpointsTest_EndpointCreateThenOfferRemove_yGtovE"
I0809 01:05:00.229665   757 credentials.hpp:86] Loading credential for authentication from '/tmp/PersistentVolumeEndpointsTest_EndpointCreateThenOfferRemove_sGwsLe/credential'
I0809 01:05:00.229878   757 slave.cpp:283] Agent using credential for: test-principal
I0809 01:05:00.229894   757 credentials.hpp:37] Loading credentials for authentication from '/tmp/PersistentVolumeEndpointsTest_EndpointCreateThenOfferRemove_sGwsLe/http_credentials'
I0809 01:05:00.230185   757 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
I0809 01:05:00.230402   757 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
I0809 01:05:00.230620   757 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0809 01:05:00.230710   757 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
I0809 01:05:00.230885   757 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
I0809 01:05:00.230974   757 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
I0809 01:05:00.232285   757 slave.cpp:565] Agent resources: [{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"cpus","scalar":{"value":24.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":95614.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I0809 01:05:00.232491   757 slave.cpp:573] Agent attributes: [  ]
I0809 01:05:00.232501   757 slave.cpp:582] Agent hostname: dd9635de8477
I0809 01:05:00.232664   767 status_update_manager.cpp:177] Pausing sending status updates
I0809 01:05:00.234344   756 state.cpp:64] Recovering state from '/tmp/PersistentVolumeEndpointsTest_EndpointCreateThenOfferRemove_yGtovE/meta'
I0809 01:05:00.234874   774 status_update_manager.cpp:203] Recovering status update manager
I0809 01:05:00.235074   765 containerizer.cpp:598] Recovering containerizer
I0809 01:05:00.237032   758 provisioner.cpp:416] Provisioner recovery complete
I0809 01:05:00.237423   772 slave.cpp:6207] Finished recovery
I0809 01:05:00.238004   772 slave.cpp:6389] Querying resource estimator for oversubscribable resources
I0809 01:05:00.238355   774 status_update_manager.cpp:177] Pausing sending status updates
I0809 01:05:00.238368   756 slave.cpp:971] New master detected at master@172.17.0.4:42552
I0809 01:05:00.238505   756 slave.cpp:1006] Detecting new master
I0809 01:05:00.238735   756 slave.cpp:6403] Received oversubscribable resources {} from the resource estimator
I0809 01:05:00.243163   754 slave.cpp:1033] Authenticating with master master@172.17.0.4:42552
I0809 01:05:00.243301   754 slave.cpp:1044] Using default CRAM-MD5 authenticatee
I0809 01:05:00.243651   760 authenticatee.cpp:121] Creating new client SASL connection
I0809 01:05:00.244027   760 master.cpp:7837] Authenticating slave(466)@172.17.0.4:42552
I0809 01:05:00.244140   761 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(960)@172.17.0.4:42552
I0809 01:05:00.244392   767 authenticator.cpp:98] Creating new server SASL connection
I0809 01:05:00.244676   767 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0809 01:05:00.244704   767 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0809 01:05:00.244799   767 authenticator.cpp:204] Received SASL authentication start
I0809 01:05:00.244855   767 authenticator.cpp:326] Authentication requires more steps
I0809 01:05:00.244945   767 authenticatee.cpp:259] Received SASL authentication step
I0809 01:05:00.245061   762 authenticator.cpp:232] Received SASL authentication step
I0809 01:05:00.245095   762 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'dd9635de8477' server FQDN: 'dd9635de8477' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0809 01:05:00.245108   762 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0809 01:05:00.245151   762 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0809 01:05:00.245167   762 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'dd9635de8477' server FQDN: 'dd9635de8477' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0809 01:05:00.245177   762 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0809 01:05:00.245182   762 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0809 01:05:00.245198   762 authenticator.cpp:318] Authentication success
I0809 01:05:00.245280   775 authenticatee.cpp:299] Authentication success
I0809 01:05:00.245352   753 master.cpp:7867] Successfully authenticated principal 'test-principal' at slave(466)@172.17.0.4:42552
I0809 01:05:00.245559   775 slave.cpp:1128] Successfully authenticated with master master@172.17.0.4:42552
I0809 01:05:00.245779   775 slave.cpp:1572] Will retry registration in 6.042179ms if necessary
I0809 01:05:00.245898   762 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(960)@172.17.0.4:42552
I0809 01:05:00.245999   772 master.cpp:5712] Received register agent message from slave(466)@172.17.0.4:42552 (dd9635de8477)
I0809 01:05:00.246037   772 master.cpp:3803] Authorizing agent with principal 'test-principal'
I0809 01:05:00.246551   774 master.cpp:5772] Authorized registration of agent at slave(466)@172.17.0.4:42552 (dd9635de8477)
I0809 01:05:00.246652   774 master.cpp:5865] Registering agent at slave(466)@172.17.0.4:42552 (dd9635de8477) with id 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-S0
I0809 01:05:00.247103   774 registrar.cpp:495] Applied 1 operations in 68917ns; attempting to update the registry
I0809 01:05:00.247838   774 registrar.cpp:552] Successfully updated the registry in 658176ns
I0809 01:05:00.248143   774 master.cpp:5912] Admitted agent 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-S0 at slave(466)@172.17.0.4:42552 (dd9635de8477)
I0809 01:05:00.248879   774 master.cpp:5943] Registered agent 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-S0 at slave(466)@172.17.0.4:42552 (dd9635de8477) with [{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"cpus","scalar":{"value":24.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":95614.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I0809 01:05:00.249223   774 slave.cpp:4883] Received ping from slave-observer(461)@172.17.0.4:42552
I0809 01:05:00.249393   765 hierarchical.cpp:593] Added agent 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-S0 (dd9635de8477) with disk:1024; cpus:24; mem:95614; ports:[31000-32000] (allocated: {})
I0809 01:05:00.249501   774 slave.cpp:1174] Registered with master master@172.17.0.4:42552; given agent ID 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-S0
I0809 01:05:00.249653   773 status_update_manager.cpp:184] Resuming sending status updates
I0809 01:05:00.249711   765 hierarchical.cpp:1925] No allocations performed
I0809 01:05:00.249759   765 hierarchical.cpp:1468] Performed allocation for 1 agents in 190312ns
I0809 01:05:00.249954   774 slave.cpp:1194] Checkpointing SlaveInfo to '/tmp/PersistentVolumeEndpointsTest_EndpointCreateThenOfferRemove_yGtovE/meta/slaves/9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-S0/slave.info'
I0809 01:05:00.252825   764 process.cpp:3933] Handling HTTP event for process 'master' with path: '/master/reserve'
I0809 01:05:00.254849   767 http.cpp:1166] HTTP POST for /master/reserve from 172.17.0.4:52290
I0809 01:05:00.255381   767 master.cpp:3588] Authorizing principal 'test-principal' to reserve resources '[{"name":"disk","reservations":[{"principal":"test-principal","role":"role1","type":"DYNAMIC"}],"scalar":{"value":512.0},"type":"SCALAR"}]'
I0809 01:05:00.258602   763 master.cpp:9110] Sending updated checkpointed resources disk(reservations: [(DYNAMIC,role1,test-principal)]):512 to agent 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-S0 at slave(466)@172.17.0.4:42552 (dd9635de8477)
I0809 01:05:00.258657   767 hierarchical.cpp:1925] No allocations performed
I0809 01:05:00.258708   767 hierarchical.cpp:1468] Performed allocation for 1 agents in 194898ns
I0809 01:05:00.270818   762 process.cpp:3933] Handling HTTP event for process 'master' with path: '/master/create-volumes'
I0809 01:05:00.272119   764 http.cpp:1166] HTTP POST for /master/create-volumes from 172.17.0.4:52292
I0809 01:05:00.273106   764 master.cpp:3723] Authorizing principal 'test-principal' to create volumes '[{"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"volume_path","mode":"RW"}},"name":"disk","reservations":[{"principal":"test-principal","role":"role1","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"}]'
I0809 01:05:00.276558   774 slave.cpp:1232] Forwarding total oversubscribed resources {}
I0809 01:05:00.276837   759 master.cpp:6688] Received update of agent 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-S0 at slave(466)@172.17.0.4:42552 (dd9635de8477) with total oversubscribed resources {}
I0809 01:05:00.277446   759 master.cpp:9110] Sending updated checkpointed resources disk(reservations: [(DYNAMIC,role1,test-principal)]):511; disk(reservations: [(DYNAMIC,role1,test-principal)])[id1:volume_path]:1 to agent 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-S0 at slave(466)@172.17.0.4:42552 (dd9635de8477)
I0809 01:05:00.277650   774 slave.cpp:3445] Updated checkpointed resources from {} to disk(reservations: [(DYNAMIC,role1,test-principal)]):512
I0809 01:05:00.278642   760 hierarchical.cpp:660] Agent 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-S0 (dd9635de8477) updated with total resources disk:512; cpus:24; mem:95614; ports:[31000-32000]; disk(reservations: [(DYNAMIC,role1,test-principal)]):512
I0809 01:05:00.278991   760 hierarchical.cpp:1925] No allocations performed
I0809 01:05:00.279047   760 hierarchical.cpp:1468] Performed allocation for 1 agents in 204620ns
I0809 01:05:00.281262   751 process.cpp:3228] Attempting to spawn already spawned process version@172.17.0.4:42552
I0809 01:05:00.282403   751 sched.cpp:232] Version: 1.4.0
I0809 01:05:00.283011   752 sched.cpp:336] New master detected at master@172.17.0.4:42552
I0809 01:05:00.283107   752 sched.cpp:407] Authenticating with master master@172.17.0.4:42552
I0809 01:05:00.283125   752 sched.cpp:414] Using default CRAM-MD5 authenticatee
I0809 01:05:00.283499   758 authenticatee.cpp:121] Creating new client SASL connection
I0809 01:05:00.283871   759 master.cpp:7837] Authenticating scheduler-8db0f606-0cb4-4c77-81c7-64a713e776a8@172.17.0.4:42552
I0809 01:05:00.283975   760 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(961)@172.17.0.4:42552
I0809 01:05:00.284229   753 authenticator.cpp:98] Creating new server SASL connection
I0809 01:05:00.284431   773 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0809 01:05:00.284454   773 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0809 01:05:00.284550   766 authenticator.cpp:204] Received SASL authentication start
I0809 01:05:00.284605   766 authenticator.cpp:326] Authentication requires more steps
I0809 01:05:00.284696   765 authenticatee.cpp:259] Received SASL authentication step
I0809 01:05:00.284806   772 authenticator.cpp:232] Received SASL authentication step
I0809 01:05:00.284833   772 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'dd9635de8477' server FQDN: 'dd9635de8477' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0809 01:05:00.284844   772 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0809 01:05:00.284885   772 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0809 01:05:00.284901   772 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'dd9635de8477' server FQDN: 'dd9635de8477' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0809 01:05:00.284911   772 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0809 01:05:00.284922   772 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0809 01:05:00.284940   772 authenticator.cpp:318] Authentication success
I0809 01:05:00.285022   762 authenticatee.cpp:299] Authentication success
I0809 01:05:00.285079   769 master.cpp:7867] Successfully authenticated principal 'test-principal' at scheduler-8db0f606-0cb4-4c77-81c7-64a713e776a8@172.17.0.4:42552
I0809 01:05:00.285137   762 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(961)@172.17.0.4:42552
I0809 01:05:00.285291   763 sched.cpp:513] Successfully authenticated with master master@172.17.0.4:42552
I0809 01:05:00.285310   763 sched.cpp:836] Sending SUBSCRIBE call to master@172.17.0.4:42552
I0809 01:05:00.285435   763 sched.cpp:869] Will retry registration in 1.285180218secs if necessary
I0809 01:05:00.285661   771 master.cpp:2894] Received SUBSCRIBE call for framework 'default' at scheduler-8db0f606-0cb4-4c77-81c7-64a713e776a8@172.17.0.4:42552
I0809 01:05:00.285691   771 master.cpp:2228] Authorizing framework principal 'test-principal' to receive offers for roles '{ role1 }'
I0809 01:05:00.286295   756 master.cpp:2974] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
I0809 01:05:00.286837   752 sched.cpp:759] Framework registered with 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-0000
I0809 01:05:00.286892   752 sched.cpp:773] Scheduler::registered took 36340ns
I0809 01:05:00.287026   764 hierarchical.cpp:303] Added framework 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-0000
I0809 01:05:00.288655   764 hierarchical.cpp:2015] No inverse offers to send out!
I0809 01:05:00.288703   764 hierarchical.cpp:1468] Performed allocation for 1 agents in 1.52997ms
I0809 01:05:00.289235   759 master.cpp:7667] Sending 1 offers to framework 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-0000 (default) at scheduler-8db0f606-0cb4-4c77-81c7-64a713e776a8@172.17.0.4:42552
I0809 01:05:00.289839   760 sched.cpp:933] Scheduler::resourceOffers took 152179ns
/mesos/src/tests/persistent_volume_endpoints_tests.cpp:1729: Failure
Value of: Resources(offer.resources()).contains( allocatedResources(volume, frameworkInfo.role()))
  Actual: false
Expected: true
I0809 01:05:00.291872   757 master.cpp:9164] Removing offer 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-O0
I0809 01:05:00.292019   757 master.cpp:4153] Processing ACCEPT call for offers: [ 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-O0 ] on agent 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-S0 at slave(466)@172.17.0.4:42552 (dd9635de8477) for framework 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-0000 (default) at scheduler-8db0f606-0cb4-4c77-81c7-64a713e776a8@172.17.0.4:42552
I0809 01:05:00.292181   757 master.cpp:3775] Authorizing principal 'test-principal' to destroy volumes '[{"allocation_info":{"role":"role1"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"volume_path","mode":"RW"}},"name":"disk","reservations":[{"principal":"test-principal","role":"role1","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"}]'
W0809 01:05:00.293149   757 master.cpp:2313] Dropping DESTROY offer operation from framework 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-0000 (default) at scheduler-8db0f606-0cb4-4c77-81c7-64a713e776a8@172.17.0.4:42552: Invalid DESTROY Operation: Persistent volume does not exist
I0809 01:05:00.294728   752 hierarchical.cpp:1152] Recovered disk(allocated: role1):512; cpus(allocated: role1):24; mem(allocated: role1):95614; ports(allocated: role1):[31000-32000]; disk(allocated: role1)(reservations: [(DYNAMIC,role1,test-principal)]):512 (total: disk:512; cpus:24; mem:95614; ports:[31000-32000]; disk(reservations: [(DYNAMIC,role1,test-principal)]):512, allocated: {}) on agent 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-S0 from framework 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-0000
I0809 01:05:00.312685   758 hierarchical.cpp:2015] No inverse offers to send out!
I0809 01:05:00.312762   758 hierarchical.cpp:1468] Performed allocation for 1 agents in 1.713821ms
I0809 01:05:00.313539   764 master.cpp:7667] Sending 1 offers to framework 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-0000 (default) at scheduler-8db0f606-0cb4-4c77-81c7-64a713e776a8@172.17.0.4:42552
I0809 01:05:00.314146   759 sched.cpp:933] Scheduler::resourceOffers took 112842ns
I0809 01:05:00.316143   767 master.cpp:9164] Removing offer 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-O1
I0809 01:05:00.316256   767 master.cpp:4153] Processing ACCEPT call for offers: [ 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-O1 ] on agent 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-S0 at slave(466)@172.17.0.4:42552 (dd9635de8477) for framework 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-0000 (default) at scheduler-8db0f606-0cb4-4c77-81c7-64a713e776a8@172.17.0.4:42552
I0809 01:05:00.316395   767 master.cpp:3656] Authorizing principal 'test-principal' to unreserve resources '[{"allocation_info":{"role":"role1"},"name":"disk","reservations":[{"principal":"test-principal","role":"role1","type":"DYNAMIC"}],"scalar":{"value":512.0},"type":"SCALAR"}]'
I0809 01:05:00.317443   767 master.cpp:4511] Applying UNRESERVE operation for resources [{"allocation_info":{"role":"role1"},"name":"disk","reservations":[{"principal":"test-principal","role":"role1","type":"DYNAMIC"}],"scalar":{"value":512.0},"type":"SCALAR"}] from framework 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-0000 (default) at scheduler-8db0f606-0cb4-4c77-81c7-64a713e776a8@172.17.0.4:42552 to agent 9a4ed888-b5ab-4bf3-9dfa-3d843cb91165-S0 at slave(466)@172.17.0.4:42552 (dd9635de8477)
F0809 01:05:00.317688   767 master.cpp:9860] CHECK_SOME(resources): Invalid UNRESERVE Operation: disk:512; cpus:24; mem:95614; ports:[31000-32000]; disk(reservations: [(DYNAMIC,role1,test-principal)]):511; disk(reservations: [(DYNAMIC,role1,test-principal)])[id1:volume_path]:1 does not contain disk(reservations: [(DYNAMIC,role1,test-principal)]):512 
*** Check failure stack trace: ***
    @     0x2b48c55e4a53  google::LogMessage::SendToLog()
    @     0x2b48c55e4ecf  google::LogMessage::Flush()
    @     0x2b48c55e895d  google::LogMessageFatal::~LogMessageFatal()
    @          0x1b89c37  _CheckFatal::~_CheckFatal()
    @     0x2b48c0b53101  mesos::internal::master::Slave::apply()
    @     0x2b48c0b398c5  mesos::internal::master::Master::_apply()
    @     0x2b48c0b33698  mesos::internal::master::Master::_accept()
    @     0x2b48c0bf1f87  _ZZN7process8dispatchIN5mesos8internal6master6MasterERKNS1_11FrameworkIDERKNS1_7SlaveIDERKNS1_9ResourcesERKNS1_9scheduler11Call_AcceptERKNS_6FutureISt4listINSI_IbEESaISK_EEEES7_SA_SD_SH_SP_EEvRKNS_3PIDIT_EEMSR_FvT0_T1_T2_T3_T4_EOT5_OT6_OT7_OT8_OT9_ENKUlRS5_RS8_RSB_RSF_RSN_PNS_11ProcessBaseEE_clES1C_S1D_S1E_S1F_S1G_S1I_
I0809 01:05:00.363899   752 hierarchical.cpp:1925] No allocations performed
I0809 01:05:00.363968   752 hierarchical.cpp:2015] No inverse offers to send out!
I0809 01:05:00.364003   752 hierarchical.cpp:1468] Performed allocation for 1 agents in 313207ns
    @     0x2b48c0bf1e01  _ZNSt5_BindIFZN7process8dispatchIN5mesos8internal6master6MasterERKNS2_11FrameworkIDERKNS2_7SlaveIDERKNS2_9ResourcesERKNS2_9scheduler11Call_AcceptERKNS0_6FutureISt4listINSJ_IbEESaISL_EEEES8_SB_SE_SI_SQ_EEvRKNS0_3PIDIT_EEMSS_FvT0_T1_T2_T3_T4_EOT5_OT6_OT7_OT8_OT9_EUlRS6_RS9_RSC_RSG_RSO_PNS0_11ProcessBaseEE_S6_S9_SC_SG_SO_St12_PlaceholderILi1EEEE6__callIvJOS1J_EJLm0ELm1ELm2ELm3ELm4ELm5EEEESS_OSt5tupleIJDpT0_EESt12_Index_tupleIJXspT1_EEE
    @     0x2b48c0bf1ccd  _ZNSt5_BindIFZN7process8dispatchIN5mesos8internal6master6MasterERKNS2_11FrameworkIDERKNS2_7SlaveIDERKNS2_9ResourcesERKNS2_9scheduler11Call_AcceptERKNS0_6FutureISt4listINSJ_IbEESaISL_EEEES8_SB_SE_SI_SQ_EEvRKNS0_3PIDIT_EEMSS_FvT0_T1_T2_T3_T4_EOT5_OT6_OT7_OT8_OT9_EUlRS6_RS9_RSC_RSG_RSO_PNS0_11ProcessBaseEE_S6_S9_SC_SG_SO_St12_PlaceholderILi1EEEEclIJS1J_EvEESW_DpOT_
    @     0x2b48c0bf17a2  _ZNSt17_Function_handlerIFvPN7process11ProcessBaseEESt5_BindIFZNS0_8dispatchIN5mesos8internal6master6MasterERKNS6_11FrameworkIDERKNS6_7SlaveIDERKNS6_9ResourcesERKNS6_9scheduler11Call_AcceptERKNS0_6FutureISt4listINSN_IbEESaISP_EEEESC_SF_SI_SM_SU_EEvRKNS0_3PIDIT_EEMSW_FvT0_T1_T2_T3_T4_EOT5_OT6_OT7_OT8_OT9_EUlRSA_RSD_RSG_RSK_RSS_S2_E_SA_SD_SG_SK_SS_St12_PlaceholderILi1EEEEE9_M_invokeERKSt9_Any_dataS2_
    @     0x2b48c311fda8  std::function<>::operator()()
    @     0x2b48c3103f74  process::ProcessBase::visit()
    @     0x2b48c31a8f8e  process::DispatchEvent::visit()
    @          0x1bcc3f1  process::ProcessBase::serve()
    @     0x2b48c3101d1f  process::ProcessManager::resume()
    @     0x2b48c3110891  process::ProcessManager::init_threads()::$_9::operator()()
    @     0x2b48c31107d5  _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvE3$_9vEE9_M_invokeIJEEEvSt12_Index_tupleIJXspT_EEE
    @     0x2b48c31107a5  std::_Bind_simple<>::operator()()
    @     0x2b48c311077c  std::thread::_Impl<>::_M_run()
    @     0x2b48c78e4a60  (unknown)
    @     0x2b48c761d184  start_thread
    @     0x2b48c8150ffd  (unknown)
make[3]: Leaving directory `/mesos/build'
make[2]: Leaving directory `/mesos/build'
make[3]: *** [CMakeFiles/check] Aborted (core dumped)
make[2]: *** [CMakeFiles/check.dir/all] Error 2
make[1]: Leaving directory `/mesos/build'
make[1]: *** [CMakeFiles/check.dir/rule] Error 2
make: *** [check] Error 2
+ docker rmi mesos-1502238525-14571
Untagged: mesos-1502238525-14571:latest
Deleted: sha256:4ef4933cff30b361c16428b3cd982257b80c167cbfcae60e6d381b6b9009ba72
Deleted: sha256:7a3891747d29d27fe08efb92399d627d61bcb0da9d20eca6060653963e7b9c6f
Deleted: sha256:bf84f284421e5d4003ed7a587a3c7530754f75f1e3507e687938ff956f6d96f4
Deleted: sha256:bbe754d35e4f1f3a6f1e3551b1753d9298ea1493603bdc6be78d3a1f0ab44043
Deleted: sha256:f2f3fa4e71fdf33175e08a687de9853bb01a396e25e14d0c74580feb98248f6b
Deleted: sha256:8a7ba94ee61dd5a57c11f8e636269a23590bfb22b275cc567a5f38c7d009cafa
Deleted: sha256:0638e2839056a54dfd098ec4730321f2f15f2461350f5bcfeb028d96c61f5ef0
Deleted: sha256:25ae62f00f21a72b1ebe8a63d33b23479a33e6bd7e09b614e28134e3e203c6bd
Deleted: sha256:dc4bcd14129e0ca65035f902cf28315d223e6483b98e9e9f78490ef2eb1b682a
Deleted: sha256:6004fefe6616c101e5d7fd208136998538a03bbb7aaaaefb6e286d6c84664c74
Deleted: sha256:738771cad0f2e1350ece88bbd11fb08555e84e2b0cd253013a92b49ac7b926a3
Deleted: sha256:ac59c077c0706001a6c7e22fa9a15db9d92d308caa60b71f857176f859344b32
Deleted: sha256:040a15118d2e22e9b2a80c14c6a8b2f860b083a8bce2b5032868ec962ec646a0
Deleted: sha256:761a39e2fd60ff228f187d5713fe52e8a0a8f7304b514ad7fde78913bab21419
Deleted: sha256:8ece89b469b8eda57f91649b309d779da1053ee83e067dbc91f4426a68640036
Deleted: sha256:da1b6f977c896cddff65c1ed448be8a98289c53cec4fe49b3ba38e17a17f0975
Deleted: sha256:ccb6b40780b1c1d59436a7e822e489b4fd1ce70b0013881dea60d8a5d5b1cd4d
Deleted: sha256:37a9598c33bb9ab34a522bfd86da499ff8b66a13568f6d222fa3d59a45f29464
Deleted: sha256:7d78f86981f85f11773aa2c27a0ce394d93d2ae50b79603756ed3cabc1af7862
Deleted: sha256:de6e6833df1f869b0cdb2019b3ae8eb1c09b59afe68b25cdd4496bce057747d1
Deleted: sha256:61287c334cb0f5142780001931b11be7ca662bea629262633b237e51d64638e6
Deleted: sha256:070d6ba9b51a014ed1e7245c2b4e5d330560ad83bfa9243958f5b11f2f731844
Deleted: sha256:a26acc60dda48c62920f5ff86aea98b0b6b9fbe33e67640b801f8673c64fa3f1
Deleted: sha256:19f36506bdf842c5020af8265fe0bc056b0be47033f74aefeac1681d8abd9e85
Build step 'Execute shell' marked build as failure