See
<https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)/4105/display/redirect>
------------------------------------------
[...truncated 17.64 MB...]
I0812 10:50:15.286759 31553 process.cpp:3933] Handling HTTP event for process
'master' with path: '/master/reserve'
I0812 10:50:15.287777 31565 slave.cpp:1194] Checkpointing SlaveInfo to
'/tmp/PersistentVolumeEndpointsTest_DynamicReservationRoleMismatch_Up7Gpp/meta/slaves/25e97175-d615-492a-890b-b6e1d1c1184a-S0/slave.info'
I0812 10:50:15.288151 31555 http.cpp:1166] HTTP POST for /master/reserve from
172.17.0.2:33925
I0812 10:50:15.288163 31565 slave.cpp:1232] Forwarding total oversubscribed
resources {}
I0812 10:50:15.288615 31555 master.cpp:3588] Authorizing principal
'test-principal' to reserve resources
'[{"name":"disk","reservations":[{"principal":"test-principal","role":"role1","type":"DYNAMIC"}],"scalar":{"value":1024.0},"type":"SCALAR"}]'
I0812 10:50:15.289216 31555 master.cpp:6688] Received update of agent
25e97175-d615-492a-890b-b6e1d1c1184a-S0 at slave(447)@172.17.0.2:49532
(4c851870f6a8) with total oversubscribed resources {}
I0812 10:50:15.289680 31557 hierarchical.cpp:660] Agent
25e97175-d615-492a-890b-b6e1d1c1184a-S0 (4c851870f6a8) updated with total
resources disk:1024; cpus:16; mem:47270; ports:[31000-32000]
I0812 10:50:15.291615 31566 master.cpp:9110] Sending updated checkpointed
resources disk(reservations: [(DYNAMIC,role1,test-principal)]):1024 to agent
25e97175-d615-492a-890b-b6e1d1c1184a-S0 at slave(447)@172.17.0.2:49532
(4c851870f6a8)
I0812 10:50:15.292546 31558 slave.cpp:3449] Updated checkpointed resources from
{} to disk(reservations: [(DYNAMIC,role1,test-principal)]):1024
I0812 10:50:15.293223 31552 process.cpp:3228] Attempting to spawn already
spawned process version@172.17.0.2:49532
I0812 10:50:15.294324 31552 sched.cpp:232] Version: 1.4.0
I0812 10:50:15.294970 31554 sched.cpp:336] New master detected at
master@172.17.0.2:49532
I0812 10:50:15.295096 31554 sched.cpp:407] Authenticating with master
master@172.17.0.2:49532
I0812 10:50:15.295120 31554 sched.cpp:414] Using default CRAM-MD5 authenticatee
I0812 10:50:15.295346 31558 authenticatee.cpp:121] Creating new client SASL
connection
I0812 10:50:15.295624 31561 master.cpp:7837] Authenticating
scheduler-c539430f-7b82-477d-b249-a1694e8d8bd2@172.17.0.2:49532
I0812 10:50:15.295730 31563 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(932)@172.17.0.2:49532
I0812 10:50:15.296037 31564 authenticator.cpp:98] Creating new server SASL
connection
I0812 10:50:15.296284 31560 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I0812 10:50:15.296314 31560 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0812 10:50:15.296439 31555 authenticator.cpp:204] Received SASL authentication
start
I0812 10:50:15.296497 31555 authenticator.cpp:326] Authentication requires more
steps
I0812 10:50:15.296591 31555 authenticatee.cpp:259] Received SASL authentication
step
I0812 10:50:15.296697 31555 authenticator.cpp:232] Received SASL authentication
step
I0812 10:50:15.296725 31555 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '4c851870f6a8' server FQDN: '4c851870f6a8'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I0812 10:50:15.296736 31555 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I0812 10:50:15.296772 31555 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0812 10:50:15.296794 31555 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '4c851870f6a8' server FQDN: '4c851870f6a8'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
I0812 10:50:15.296808 31555 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0812 10:50:15.296814 31555 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0812 10:50:15.296831 31555 authenticator.cpp:318] Authentication success
I0812 10:50:15.296933 31553 authenticatee.cpp:299] Authentication success
I0812 10:50:15.297046 31562 master.cpp:7867] Successfully authenticated
principal 'test-principal' at
scheduler-c539430f-7b82-477d-b249-a1694e8d8bd2@172.17.0.2:49532
I0812 10:50:15.297134 31555 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(932)@172.17.0.2:49532
I0812 10:50:15.297267 31553 sched.cpp:513] Successfully authenticated with
master master@172.17.0.2:49532
I0812 10:50:15.297343 31553 sched.cpp:836] Sending SUBSCRIBE call to
master@172.17.0.2:49532
I0812 10:50:15.297526 31553 sched.cpp:869] Will retry registration in
1.772875033secs if necessary
I0812 10:50:15.297758 31558 master.cpp:2894] Received SUBSCRIBE call for
framework 'default' at
scheduler-c539430f-7b82-477d-b249-a1694e8d8bd2@172.17.0.2:49532
I0812 10:50:15.297855 31558 master.cpp:2228] Authorizing framework principal
'test-principal' to receive offers for roles '{ role1 }'
I0812 10:50:15.298414 31559 master.cpp:2974] Subscribing framework default with
checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
I0812 10:50:15.299057 31567 sched.cpp:759] Framework registered with
25e97175-d615-492a-890b-b6e1d1c1184a-0000
I0812 10:50:15.299116 31567 sched.cpp:773] Scheduler::registered took 29294ns
I0812 10:50:15.299151 31564 hierarchical.cpp:303] Added framework
25e97175-d615-492a-890b-b6e1d1c1184a-0000
I0812 10:50:15.300492 31564 hierarchical.cpp:2015] No inverse offers to send
out!
I0812 10:50:15.300546 31564 hierarchical.cpp:1468] Performed allocation for 1
agents in 1.251655ms
I0812 10:50:15.301221 31565 master.cpp:7667] Sending 1 offers to framework
25e97175-d615-492a-890b-b6e1d1c1184a-0000 (default) at
scheduler-c539430f-7b82-477d-b249-a1694e8d8bd2@172.17.0.2:49532
I0812 10:50:15.301880 31554 sched.cpp:933] Scheduler::resourceOffers took
135959ns
I0812 10:50:15.305358 31562 process.cpp:3933] Handling HTTP event for process
'master' with path: '/master/create-volumes'
I0812 10:50:15.306957 31568 http.cpp:1166] HTTP POST for /master/create-volumes
from 172.17.0.2:33926
I0812 10:50:15.307756 31568 master.cpp:3723] Authorizing principal
'test-principal' to create volumes
'[{"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"principal":"test-principal","role":"role2","type":"DYNAMIC"}],"scalar":{"value":64.0},"type":"SCALAR"}]'
I0812 10:50:15.310726 31552 sched.cpp:2021] Asked to stop the driver
I0812 10:50:15.310895 31558 sched.cpp:1203] Stopping framework
25e97175-d615-492a-890b-b6e1d1c1184a-0000
I0812 10:50:15.311168 31559 master.cpp:8348] Processing TEARDOWN call for
framework 25e97175-d615-492a-890b-b6e1d1c1184a-0000 (default) at
scheduler-c539430f-7b82-477d-b249-a1694e8d8bd2@172.17.0.2:49532
I0812 10:50:15.311203 31559 master.cpp:8360] Removing framework
25e97175-d615-492a-890b-b6e1d1c1184a-0000 (default) at
scheduler-c539430f-7b82-477d-b249-a1694e8d8bd2@172.17.0.2:49532
I0812 10:50:15.311234 31559 master.cpp:3264] Deactivating framework
25e97175-d615-492a-890b-b6e1d1c1184a-0000 (default) at
scheduler-c539430f-7b82-477d-b249-a1694e8d8bd2@172.17.0.2:49532
I0812 10:50:15.311426 31557 hierarchical.cpp:412] Deactivated framework
25e97175-d615-492a-890b-b6e1d1c1184a-0000
I0812 10:50:15.312113 31559 master.cpp:9164] Removing offer
25e97175-d615-492a-890b-b6e1d1c1184a-O0
I0812 10:50:15.312326 31564 slave.cpp:3159] Asked to shut down framework
25e97175-d615-492a-890b-b6e1d1c1184a-0000 by master@172.17.0.2:49532
I0812 10:50:15.312358 31564 slave.cpp:3174] Cannot shut down unknown framework
25e97175-d615-492a-890b-b6e1d1c1184a-0000
I0812 10:50:15.312834 31557 hierarchical.cpp:1152] Recovered ports(allocated:
role1):[31000-32000]; cpus(allocated: role1):16; mem(allocated: role1):47270;
disk(allocated: role1)(reservations: [(DYNAMIC,role1,test-principal)]):1024
(total: ports:[31000-32000]; cpus:16; mem:47270; disk(reservations:
[(DYNAMIC,role1,test-principal)]):1024, allocated: {}) on agent
25e97175-d615-492a-890b-b6e1d1c1184a-S0 from framework
25e97175-d615-492a-890b-b6e1d1c1184a-0000
I0812 10:50:15.312978 31564 slave.cpp:843] Agent terminating
I0812 10:50:15.313161 31562 master.cpp:1318] Agent
25e97175-d615-492a-890b-b6e1d1c1184a-S0 at slave(447)@172.17.0.2:49532
(4c851870f6a8) disconnected
I0812 10:50:15.313190 31562 master.cpp:3301] Disconnecting agent
25e97175-d615-492a-890b-b6e1d1c1184a-S0 at slave(447)@172.17.0.2:49532
(4c851870f6a8)
I0812 10:50:15.313285 31557 hierarchical.cpp:355] Removed framework
25e97175-d615-492a-890b-b6e1d1c1184a-0000
I0812 10:50:15.313336 31562 master.cpp:3320] Deactivating agent
25e97175-d615-492a-890b-b6e1d1c1184a-S0 at slave(447)@172.17.0.2:49532
(4c851870f6a8)
I0812 10:50:15.313454 31561 hierarchical.cpp:690] Agent
25e97175-d615-492a-890b-b6e1d1c1184a-S0 deactivated
I0812 10:50:15.320636 31552 master.cpp:1160] Master terminating
I0812 10:50:15.321581 31568 hierarchical.cpp:626] Removed agent
25e97175-d615-492a-890b-b6e1d1c1184a-S0
[ OK ] PersistentVolumeEndpointsTest.DynamicReservationRoleMismatch (108
ms)
[ RUN ] PersistentVolumeEndpointsTest.UnreserveVolumeResources
I0812 10:50:15.332918 31552 cluster.cpp:162] Creating default 'local' authorizer
I0812 10:50:15.336380 31554 master.cpp:442] Master
2aac1248-9bc8-462f-9550-019f6c85fe93 (4c851870f6a8) started on 172.17.0.2:49532
I0812 10:50:15.336442 31554 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/gYSykE/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/gYSykE/master"
--zk_session_timeout="10secs"
I0812 10:50:15.336943 31554 master.cpp:494] Master only allowing authenticated
frameworks to register
I0812 10:50:15.336962 31554 master.cpp:508] Master only allowing authenticated
agents to register
I0812 10:50:15.336973 31554 master.cpp:521] Master only allowing authenticated
HTTP frameworks to register
I0812 10:50:15.336988 31554 credentials.hpp:37] Loading credentials for
authentication from '/tmp/gYSykE/credentials'
I0812 10:50:15.337393 31554 master.cpp:566] Using default 'crammd5'
authenticator
I0812 10:50:15.337664 31554 http.cpp:1026] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readonly'
I0812 10:50:15.337880 31554 http.cpp:1026] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readwrite'
I0812 10:50:15.338042 31554 http.cpp:1026] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-scheduler'
I0812 10:50:15.338181 31554 master.cpp:646] Authorization enabled
W0812 10:50:15.338198 31554 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
I0812 10:50:15.338424 31558 whitelist_watcher.cpp:77] No whitelist given
I0812 10:50:15.338429 31567 hierarchical.cpp:171] Initialized hierarchical
allocator process
I0812 10:50:15.341552 31565 master.cpp:2163] Elected as the leading master!
I0812 10:50:15.341583 31565 master.cpp:1702] Recovering from registrar
I0812 10:50:15.341743 31559 registrar.cpp:347] Recovering registrar
I0812 10:50:15.342370 31559 registrar.cpp:391] Successfully fetched the
registry (0B) in 585728ns
I0812 10:50:15.342470 31559 registrar.cpp:495] Applied 1 operations in 25748ns;
attempting to update the registry
I0812 10:50:15.343053 31559 registrar.cpp:552] Successfully updated the
registry in 527104ns
I0812 10:50:15.343170 31559 registrar.cpp:424] Successfully recovered registrar
I0812 10:50:15.343515 31566 master.cpp:1801] Recovered 0 agents from the
registry (129B); allowing 10mins for agents to re-register
I0812 10:50:15.343569 31560 hierarchical.cpp:209] Skipping recovery of
hierarchical allocator: nothing to recover
I0812 10:50:15.349115 31552 process.cpp:3228] Attempting to spawn already
spawned process files@172.17.0.2:49532
I0812 10:50:15.350283 31552 containerizer.cpp:246] Using isolation:
posix/cpu,posix/mem,filesystem/posix,network/cni,environment_secret
W0812 10:50:15.361397 31552 backend.cpp:76] Failed to create 'aufs' backend:
AufsBackend requires root privileges
W0812 10:50:15.361493 31552 backend.cpp:76] Failed to create 'bind' backend:
BindBackend requires root privileges
I0812 10:50:15.361536 31552 provisioner.cpp:255] Using default backend 'copy'
I0812 10:50:15.363253 31552 cluster.cpp:448] Creating default 'local' authorizer
I0812 10:50:15.364934 31558 slave.cpp:250] Mesos agent started on
(448)@172.17.0.2:49532
I0812 10:50:15.364953 31558 slave.cpp:251] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/PersistentVolumeEndpointsTest_UnreserveVolumeResources_avhEPl/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/PersistentVolumeEndpointsTest_UnreserveVolumeResources_avhEPl/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_UnreserveVolumeResources_avhEPl/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/PersistentVolumeEndpointsTest_UnreserveVolumeResources_avhEPl/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_UnreserveVolumeResources_avhEPl/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_UnreserveVolumeResources_avhEPl"
--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_UnreserveVolumeResources_sA254u"
I0812 10:50:15.365350 31558 credentials.hpp:86] Loading credential for
authentication from
'/tmp/PersistentVolumeEndpointsTest_UnreserveVolumeResources_avhEPl/credential'
I0812 10:50:15.365557 31558 slave.cpp:283] Agent using credential for:
test-principal
I0812 10:50:15.365583 31558 credentials.hpp:37] Loading credentials for
authentication from
'/tmp/PersistentVolumeEndpointsTest_UnreserveVolumeResources_avhEPl/http_credentials'
I0812 10:50:15.365785 31558 http.cpp:1026] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
I0812 10:50:15.365922 31558 http.cpp:1026] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readwrite'
I0812 10:50:15.366816 31558 slave.cpp:565] Agent resources:
[{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"cpus","scalar":{"value":16.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":47270.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I0812 10:50:15.366987 31558 slave.cpp:573] Agent attributes: [ ]
I0812 10:50:15.366997 31558 slave.cpp:582] Agent hostname: 4c851870f6a8
I0812 10:50:15.367117 31555 status_update_manager.cpp:177] Pausing sending
status updates
I0812 10:50:15.368404 31567 state.cpp:64] Recovering state from
'/tmp/PersistentVolumeEndpointsTest_UnreserveVolumeResources_sA254u/meta'
I0812 10:50:15.368666 31567 status_update_manager.cpp:203] Recovering status
update manager
I0812 10:50:15.368826 31561 containerizer.cpp:598] Recovering containerizer
I0812 10:50:15.370106 31567 provisioner.cpp:416] Provisioner recovery complete
I0812 10:50:15.370445 31554 slave.cpp:6210] Finished recovery
I0812 10:50:15.370851 31554 slave.cpp:6392] Querying resource estimator for
oversubscribable resources
I0812 10:50:15.371069 31563 status_update_manager.cpp:177] Pausing sending
status updates
I0812 10:50:15.371067 31554 slave.cpp:971] New master detected at
master@172.17.0.2:49532
I0812 10:50:15.371176 31554 slave.cpp:1006] Detecting new master
I0812 10:50:15.371311 31554 slave.cpp:6406] Received oversubscribable resources
{} from the resource estimator
I0812 10:50:15.376595 31561 slave.cpp:1033] Authenticating with master
master@172.17.0.2:49532
I0812 10:50:15.376654 31561 slave.cpp:1044] Using default CRAM-MD5 authenticatee
I0812 10:50:15.376889 31565 authenticatee.cpp:121] Creating new client SASL
connection
I0812 10:50:15.377162 31564 master.cpp:7837] Authenticating
slave(448)@172.17.0.2:49532
I0812 10:50:15.377265 31568 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(933)@172.17.0.2:49532
I0812 10:50:15.377522 31566 authenticator.cpp:98] Creating new server SASL
connection
I0812 10:50:15.377704 31562 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I0812 10:50:15.377725 31562 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0812 10:50:15.377820 31562 authenticator.cpp:204] Received SASL authentication
start
I0812 10:50:15.377878 31562 authenticator.cpp:326] Authentication requires more
steps
I0812 10:50:15.377974 31560 authenticatee.cpp:259] Received SASL authentication
step
I0812 10:50:15.378082 31567 authenticator.cpp:232] Received SASL authentication
step
I0812 10:50:15.378113 31567 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '4c851870f6a8' server FQDN: '4c851870f6a8'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I0812 10:50:15.378129 31567 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I0812 10:50:15.378170 31567 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0812 10:50:15.378197 31567 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '4c851870f6a8' server FQDN: '4c851870f6a8'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
I0812 10:50:15.378211 31567 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0812 10:50:15.378222 31567 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0812 10:50:15.378243 31567 authenticator.cpp:318] Authentication success
I0812 10:50:15.378427 31556 authenticatee.cpp:299] Authentication success
I0812 10:50:15.378429 31553 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(933)@172.17.0.2:49532
I0812 10:50:15.378466 31557 master.cpp:7867] Successfully authenticated
principal 'test-principal' at slave(448)@172.17.0.2:49532
I0812 10:50:15.378671 31559 slave.cpp:1128] Successfully authenticated with
master master@172.17.0.2:49532
I0812 10:50:15.378856 31559 slave.cpp:1572] Will retry registration in
3.247352ms if necessary
I0812 10:50:15.379014 31561 master.cpp:5712] Received register agent message
from slave(448)@172.17.0.2:49532 (4c851870f6a8)
I0812 10:50:15.379133 31561 master.cpp:3803] Authorizing agent with principal
'test-principal'
I0812 10:50:15.379509 31564 master.cpp:5772] Authorized registration of agent
at slave(448)@172.17.0.2:49532 (4c851870f6a8)
I0812 10:50:15.379613 31564 master.cpp:5865] Registering agent at
slave(448)@172.17.0.2:49532 (4c851870f6a8) with id
2aac1248-9bc8-462f-9550-019f6c85fe93-S0
I0812 10:50:15.380024 31568 registrar.cpp:495] Applied 1 operations in 54207ns;
attempting to update the registry
I0812 10:50:15.380596 31568 registrar.cpp:552] Successfully updated the
registry in 516352ns
I0812 10:50:15.380772 31555 master.cpp:5912] Admitted agent
2aac1248-9bc8-462f-9550-019f6c85fe93-S0 at slave(448)@172.17.0.2:49532
(4c851870f6a8)
I0812 10:50:15.381369 31556 slave.cpp:4887] Received ping from
slave-observer(444)@172.17.0.2:49532
I0812 10:50:15.381294 31555 master.cpp:5943] Registered agent
2aac1248-9bc8-462f-9550-019f6c85fe93-S0 at slave(448)@172.17.0.2:49532
(4c851870f6a8) with
[{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"cpus","scalar":{"value":16.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":47270.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I0812 10:50:15.381644 31556 slave.cpp:1174] Registered with master
master@172.17.0.2:49532; given agent ID 2aac1248-9bc8-462f-9550-019f6c85fe93-S0
I0812 10:50:15.381810 31554 hierarchical.cpp:593] Added agent
2aac1248-9bc8-462f-9550-019f6c85fe93-S0 (4c851870f6a8) with disk:1024; cpus:16;
mem:47270; ports:[31000-32000] (allocated: {})
I0812 10:50:15.381929 31561 status_update_manager.cpp:184] Resuming sending
status updates
I0812 10:50:15.382164 31554 hierarchical.cpp:1925] No allocations performed
I0812 10:50:15.382213 31554 hierarchical.cpp:1468] Performed allocation for 1
agents in 191822ns
I0812 10:50:15.384657 31555 process.cpp:3933] Handling HTTP event for process
'master' with path: '/master/reserve'
I0812 10:50:15.385956 31567 http.cpp:1166] HTTP POST for /master/reserve from
172.17.0.2:33927
I0812 10:50:15.386456 31567 master.cpp:3588] Authorizing principal
'test-principal' to reserve resources
'[{"name":"disk","reservations":[{"principal":"test-principal","role":"role1","type":"DYNAMIC"}],"scalar":{"value":1024.0},"type":"SCALAR"}]'
I0812 10:50:15.388746 31555 master.cpp:9110] Sending updated checkpointed
resources disk(reservations: [(DYNAMIC,role1,test-principal)]):1024 to agent
2aac1248-9bc8-462f-9550-019f6c85fe93-S0 at slave(448)@172.17.0.2:49532
(4c851870f6a8)
I0812 10:50:15.389120 31561 hierarchical.cpp:1925] No allocations performed
I0812 10:50:15.389171 31561 hierarchical.cpp:1468] Performed allocation for 1
agents in 170198ns
I0812 10:50:15.391633 31561 process.cpp:3933] Handling HTTP event for process
'master' with path: '/master/create-volumes'
I0812 10:50:15.393113 31563 http.cpp:1166] HTTP POST for /master/create-volumes
from 172.17.0.2:33928
I0812 10:50:15.393800 31563 master.cpp:3723] Authorizing principal
'test-principal' to create volumes
'[{"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"principal":"test-principal","role":"role1","type":"DYNAMIC"}],"scalar":{"value":64.0},"type":"SCALAR"}]'
I0812 10:50:15.394937 31556 slave.cpp:1194] Checkpointing SlaveInfo to
'/tmp/PersistentVolumeEndpointsTest_UnreserveVolumeResources_sA254u/meta/slaves/2aac1248-9bc8-462f-9550-019f6c85fe93-S0/slave.info'
I0812 10:50:15.395274 31556 slave.cpp:1232] Forwarding total oversubscribed
resources {}
I0812 10:50:15.395429 31561 master.cpp:6688] Received update of agent
2aac1248-9bc8-462f-9550-019f6c85fe93-S0 at slave(448)@172.17.0.2:49532
(4c851870f6a8) with total oversubscribed resources {}
I0812 10:50:15.395826 31556 slave.cpp:3449] Updated checkpointed resources from
{} to disk(reservations: [(DYNAMIC,role1,test-principal)]):1024
I0812 10:50:15.396389 31560 master.cpp:9110] Sending updated checkpointed
resources disk(reservations: [(DYNAMIC,role1,test-principal)]):960;
disk(reservations: [(DYNAMIC,role1,test-principal)])[id1:path1]:64 to agent
2aac1248-9bc8-462f-9550-019f6c85fe93-S0 at slave(448)@172.17.0.2:49532
(4c851870f6a8)
I0812 10:50:15.397297 31554 hierarchical.cpp:660] Agent
2aac1248-9bc8-462f-9550-019f6c85fe93-S0 (4c851870f6a8) updated with total
resources ports:[31000-32000]; cpus:16; mem:47270; disk(reservations:
[(DYNAMIC,role1,test-principal)]):1024
I0812 10:50:15.397505 31554 hierarchical.cpp:1925] No allocations performed
I0812 10:50:15.397608 31554 hierarchical.cpp:1468] Performed allocation for 1
agents in 190554ns
I0812 10:50:15.399036 31557 process.cpp:3933] Handling HTTP event for process
'master' with path: '/master/unreserve'
I0812 10:50:15.400270 31556 http.cpp:1166] HTTP POST for /master/unreserve from
172.17.0.2:33929
I0812 10:50:15.400807 31556 master.cpp:3656] Authorizing principal
'test-principal' to unreserve resources
'[{"name":"disk","reservations":[{"principal":"test-principal","role":"role1","type":"DYNAMIC"}],"scalar":{"value":1024.0},"type":"SCALAR"}]'
F0812 10:50:15.402957 31557 master.cpp:9860] CHECK_SOME(resources): Invalid
UNRESERVE Operation: ports:[31000-32000]; cpus:16; mem:47270;
disk(reservations: [(DYNAMIC,role1,test-principal)]):960; disk(reservations:
[(DYNAMIC,role1,test-principal)])[id1:path1]:64 does not contain
disk(reservations: [(DYNAMIC,role1,test-principal)]):1024
*** Check failure stack trace: ***
@ 0x7f3f97bb984d google::LogMessage::Fail()
/mesos/src/tests/persistent_volume_endpoints_tests.cpp:458: Failure
Value of: (response).get().status
Actual: "202 Accepted"
Expected: Conflict().status
Which is: "409 Conflict"
@ 0x7f3f97bbb61c google::LogMessage::SendToLog()
@ 0x7f3f97bb943c google::LogMessage::Flush()
@ 0x7f3f97bbbf2e google::LogMessageFatal::~LogMessageFatal()
@ 0x26556dc _CheckFatal::~_CheckFatal()
@ 0x7f3f9fe00b96 mesos::internal::master::Slave::apply()
@ 0x7f3f9fdfa57e mesos::internal::master::Master::_apply()
I0812 10:50:15.440655 31564 hierarchical.cpp:1925] No allocations performed
I0812 10:50:15.440714 31564 hierarchical.cpp:1468] Performed allocation for 1
agents in 211887ns
@ 0x7f3f9fe626d6
_ZZN7process8dispatchIN5mesos8internal6master6MasterEPNS3_5SlaveERKNS1_15Offer_OperationERS6_S9_EEvRKNS_3PIDIT_EEMSC_FvT0_T1_EOT2_OT3_ENKUlSA_RS7_PNS_11ProcessBaseEE_clESA_SO_SQ_
I0812 10:50:15.445353 31568 slave.cpp:3449] Updated checkpointed resources from
disk(reservations: [(DYNAMIC,role1,test-principal)]):1024 to disk(reservations:
[(DYNAMIC,role1,test-principal)]):960; disk(reservations:
[(DYNAMIC,role1,test-principal)])[id1:path1]:64
I0812 10:50:15.445456 31568 slave.cpp:843] Agent terminating
@ 0x7f3f9fefa660
_ZNSt5_BindIFZN7process8dispatchIN5mesos8internal6master6MasterEPNS4_5SlaveERKNS2_15Offer_OperationERS7_SA_EEvRKNS0_3PIDIT_EEMSD_FvT0_T1_EOT2_OT3_EUlSB_RS8_PNS0_11ProcessBaseEE_S7_S8_St12_PlaceholderILi1EEEE6__callIvJOSR_EJLm0ELm1ELm2EEEET_OSt5tupleIJDpT0_EESt12_Index_tupleIJXspT1_EEE
@ 0x7f3f9fee777b
_ZNSt5_BindIFZN7process8dispatchIN5mesos8internal6master6MasterEPNS4_5SlaveERKNS2_15Offer_OperationERS7_SA_EEvRKNS0_3PIDIT_EEMSD_FvT0_T1_EOT2_OT3_EUlSB_RS8_PNS0_11ProcessBaseEE_S7_S8_St12_PlaceholderILi1EEEEclIISR_EvEET0_DpOT_
@ 0x7f3f9fec4593
_ZNSt17_Function_handlerIFvPN7process11ProcessBaseEESt5_BindIFZNS0_8dispatchIN5mesos8internal6master6MasterEPNS8_5SlaveERKNS6_15Offer_OperationERSB_SE_EEvRKNS0_3PIDIT_EEMSH_FvT0_T1_EOT2_OT3_EUlSF_RSC_S2_E_SB_SC_St12_PlaceholderILi1EEEEE9_M_invokeERKSt9_Any_dataS2_
@ 0x7f3f9a5f50d7 std::function<>::operator()()
@ 0x7f3f9a5cf0e1 process::ProcessBase::visit()
@ 0x7f3f9a5dc0e8 process::DispatchEvent::visit()
@ 0x266f6c0 process::ProcessBase::serve()
@ 0x7f3f9a5cc94b process::ProcessManager::resume()
@ 0x7f3f9a5c8e14
_ZZN7process14ProcessManager12init_threadsEvENKUlvE_clEv
@ 0x7f3f9a5da06a
_ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE
@ 0x7f3f9a5d9fc1
_ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEclEv
@ 0x7f3f9a5d9f5a
_ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEE6_M_runEv
@ 0x7f3f95ffe230 (unknown)
@ 0x7f3f96259dc5 start_thread
@ 0x7f3f9576776d __clone
make[3]: *** [CMakeFiles/check] Aborted
make[3]: Leaving directory `/mesos/build'
make[2]: *** [CMakeFiles/check.dir/all] Error 2
make[2]: Leaving directory `/mesos/build'
make[1]: *** [CMakeFiles/check.dir/rule] Error 2
make[1]: Leaving directory `/mesos/build'
make: *** [check] Error 2
+ docker rmi mesos-1502532088-24659
Untagged: mesos-1502532088-24659:latest
Deleted: sha256:06c3651dd0a68f28f6cebe156bb64c81f1d9b2d1eb3c1be05e89be8a87aa90c8
Deleted: sha256:0837295442dc607f572dac56c37f6f9ae74d0c3bbccd4e5d58e09c73c7c32136
Deleted: sha256:1b21cb6be001ee7c1ba1dfdfb4bb361c249166017aedb60fad05bfd798925da9
Deleted: sha256:53b316238071c12e1fe00f6fb3f79dc7f9766f37a2e01bc99be2946208cbdc24
Deleted: sha256:ab029e46e504befba4de407ed49ad6bd44e3b742990089c8894f3a79d24f9f43
Deleted: sha256:22303ed8807b00cf99106c05e7c9393a18be0f19f0879ec33f274f0789ec5323
Deleted: sha256:531b01991274a2e7f092748e34387688a647edad7de37197a799630ecbca73f3
Deleted: sha256:8e910f2bb5ebfc3719b49953e19f42d235f3fac9fdc0036517660780825b7b6b
Deleted: sha256:371c7e7254bf4e340014f554903cbf7157941f10582ac34869071dd72b464b5c
Deleted: sha256:68de8c7d844d2f65a05353d2a189be0ebcfb8a600410e7d3db73e216029f1943
Deleted: sha256:d45dc78d1b6b3cc5bb9e47bb641a1318f5f471ba3c34cda6bab6f4b839d3c31a
Deleted: sha256:9b061858b9d6cc58aa5812db586f0d526ecb4ec8705da9ea32e8551bebf6dcf9
Deleted: sha256:1de498076926400efd15178d36fe656fb2800dbb53aaccbce65b284a3789b597
Deleted: sha256:903441215bafa59cd84a942131ca5f79d21e50c346a4e9ee01c9ff3ff13cf4e4
Deleted: sha256:4d01daacac8119b571f8abae5516df2936a942c960393c8017fa17deaa1d648a
Deleted: sha256:3a8ef37c5d7f0823e9826effdfe9b2870749d3805899f34b1fc4148da95e4bb2
Deleted: sha256:afc2776ac115dc10617625e212fde350176e4aec8ecc952028c77099c54c8d4a
Deleted: sha256:3dd52f44230317162ea079c33b65eae3115aa58b6879a080dee1438cc01fe7ae
Deleted: sha256:c0b04f1cbf8d04479a646ea3c661d5740d0ee0f1885130d2d080efb1b302febd
Deleted: sha256:b7edf56393dff656fb927abf2369ff7b89247991b436bd1d618b4f42ae10120e
Deleted: sha256:6500160dee675c6d107702a667bf7563cbc6ad03de935e763c2e468d781f0876
Deleted: sha256:e5d9d80a6694079314ceede6899738110414a50aa73d5ec3da9b7863f3a32523
Deleted: sha256:aa94f362a25480697cc9545f8f0229fbbbf683d6d4bed9bca1cd5dfe1dc342f9
Deleted: sha256:21d6a0e6da43ec99ade4fffef8f61948ef2dfdb5846da5907306dc6d5f1d4e1c
Deleted: sha256:0588f6f6a0ed29b6fb37dbd0d266fca37a1d3c34bdddaf98177fc63915a0f413
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user gregorywm...@gmail.com
