[MESOS-4002] ReservationEndpointsTest.UnreserveAvailableAndOfferedResources is flaky - ASF JIRA

XML

Word

Printable

JSON

Details

Type: Bug
Status: Resolved
Priority: Major
Resolution: Fixed
Affects Version/s: None
Fix Version/s: 0.27.0
Component/s: None
Labels:

Sprint:
Mesosphere Sprint 23
Story Points:
1

Description

Showed up on ASF CI: ( test kept looping on and on and ultimately failing the build after 300 minutes )
https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1269/changes

[ RUN      ] ReservationEndpointsTest.UnreserveAvailableAndOfferedResources
I1124 01:07:20.050729 30260 leveldb.cpp:174] Opened db in 107.434842ms
I1124 01:07:20.099630 30260 leveldb.cpp:181] Compacted db in 48.82312ms
I1124 01:07:20.099722 30260 leveldb.cpp:196] Created db iterator in 29905ns
I1124 01:07:20.099738 30260 leveldb.cpp:202] Seeked to beginning of db in 3145ns
I1124 01:07:20.099750 30260 leveldb.cpp:271] Iterated through 0 keys in the db in 279ns
I1124 01:07:20.099804 30260 replica.cpp:778] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1124 01:07:20.100637 30292 recover.cpp:447] Starting replica recovery
I1124 01:07:20.100934 30292 recover.cpp:473] Replica is in EMPTY status
I1124 01:07:20.103240 30288 replica.cpp:674] Replica in EMPTY status received a broadcasted recover request from (6305)@172.17.18.107:37993
I1124 01:07:20.103672 30292 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1124 01:07:20.104142 30292 recover.cpp:564] Updating replica status to STARTING
I1124 01:07:20.114534 30284 master.cpp:365] Master ad27bc60-16d1-4239-9a65-235a991f9600 (9f2f81738d5e) started on 172.17.18.107:37993
I1124 01:07:20.114558 30284 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1000secs" --allocator="HierarchicalDRF" --authenticate="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/I60I5f/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --roles="role" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.26.0/_inst/share/mesos/webui" --work_dir="/tmp/I60I5f/master" --zk_session_timeout="10secs"
I1124 01:07:20.114809 30284 master.cpp:412] Master only allowing authenticated frameworks to register
I1124 01:07:20.114820 30284 master.cpp:417] Master only allowing authenticated slaves to register
I1124 01:07:20.114825 30284 credentials.hpp:35] Loading credentials for authentication from '/tmp/I60I5f/credentials'
I1124 01:07:20.115067 30284 master.cpp:456] Using default 'crammd5' authenticator
I1124 01:07:20.115320 30284 master.cpp:493] Authorization enabled
I1124 01:07:20.115792 30285 hierarchical.cpp:162] Initialized hierarchical allocator process
I1124 01:07:20.115855 30285 whitelist_watcher.cpp:77] No whitelist given
I1124 01:07:20.118755 30285 master.cpp:1625] The newly elected leader is master@172.17.18.107:37993 with id ad27bc60-16d1-4239-9a65-235a991f9600
I1124 01:07:20.118788 30285 master.cpp:1638] Elected as the leading master!
I1124 01:07:20.118809 30285 master.cpp:1383] Recovering from registrar
I1124 01:07:20.119078 30285 registrar.cpp:307] Recovering registrar
I1124 01:07:20.143256 30292 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 38.787419ms
I1124 01:07:20.143347 30292 replica.cpp:321] Persisted replica status to STARTING
I1124 01:07:20.143717 30292 recover.cpp:473] Replica is in STARTING status
I1124 01:07:20.145454 30286 replica.cpp:674] Replica in STARTING status received a broadcasted recover request from (6307)@172.17.18.107:37993
I1124 01:07:20.145979 30292 recover.cpp:193] Received a recover response from a replica in STARTING status
I1124 01:07:20.146654 30292 recover.cpp:564] Updating replica status to VOTING
I1124 01:07:20.182672 30286 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 35.422256ms
I1124 01:07:20.182747 30286 replica.cpp:321] Persisted replica status to VOTING
I1124 01:07:20.182929 30286 recover.cpp:578] Successfully joined the Paxos group
I1124 01:07:20.183115 30286 recover.cpp:462] Recover process terminated
I1124 01:07:20.183831 30286 log.cpp:659] Attempting to start the writer
I1124 01:07:20.185907 30285 replica.cpp:494] Replica received implicit promise request from (6308)@172.17.18.107:37993 with proposal 1
I1124 01:07:20.225256 30285 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.291288ms
I1124 01:07:20.225344 30285 replica.cpp:343] Persisted promised to 1
I1124 01:07:20.226850 30286 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1124 01:07:20.228394 30293 replica.cpp:389] Replica received explicit promise request from (6309)@172.17.18.107:37993 for position 0 with proposal 2
I1124 01:07:20.266371 30293 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 37.874181ms
I1124 01:07:20.266456 30293 replica.cpp:713] Persisted action at 0
I1124 01:07:20.267927 30293 replica.cpp:538] Replica received write request for position 0 from (6310)@172.17.18.107:37993
I1124 01:07:20.268002 30293 leveldb.cpp:436] Reading position from leveldb took 37139ns
I1124 01:07:20.308117 30293 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 39.961976ms
I1124 01:07:20.308205 30293 replica.cpp:713] Persisted action at 0
I1124 01:07:20.309033 30290 replica.cpp:692] Replica received learned notice for position 0 from @0.0.0.0:0
I1124 01:07:20.343257 30290 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 34.175337ms
I1124 01:07:20.343343 30290 replica.cpp:713] Persisted action at 0
I1124 01:07:20.343377 30290 replica.cpp:698] Replica learned NOP action at position 0
I1124 01:07:20.344446 30282 log.cpp:675] Writer started with ending position 0
I1124 01:07:20.346143 30291 leveldb.cpp:436] Reading position from leveldb took 56896ns
I1124 01:07:20.347618 30291 registrar.cpp:340] Successfully fetched the registry (0B) in 228.495104ms
I1124 01:07:20.347862 30291 registrar.cpp:439] Applied 1 operations in 41164ns; attempting to update the 'registry'
I1124 01:07:20.348794 30279 log.cpp:683] Attempting to append 178 bytes to the log
I1124 01:07:20.349081 30279 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1124 01:07:20.350244 30294 replica.cpp:538] Replica received write request for position 1 from (6311)@172.17.18.107:37993
I1124 01:07:20.385246 30294 leveldb.cpp:341] Persisting action (197 bytes) to leveldb took 34.872508ms
I1124 01:07:20.385323 30294 replica.cpp:713] Persisted action at 1
I1124 01:07:20.386814 30294 replica.cpp:692] Replica received learned notice for position 1 from @0.0.0.0:0
I1124 01:07:20.425163 30294 leveldb.cpp:341] Persisting action (199 bytes) to leveldb took 38.282493ms
I1124 01:07:20.425262 30294 replica.cpp:713] Persisted action at 1
I1124 01:07:20.425298 30294 replica.cpp:698] Replica learned APPEND action at position 1
I1124 01:07:20.427994 30287 registrar.cpp:484] Successfully updated the 'registry' in 79.949056ms
I1124 01:07:20.428141 30283 log.cpp:702] Attempting to truncate the log to 1
I1124 01:07:20.428738 30287 registrar.cpp:370] Successfully recovered registrar
I1124 01:07:20.429306 30290 master.cpp:1435] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I1124 01:07:20.429592 30290 hierarchical.cpp:174] Allocator recovery is not supported yet
I1124 01:07:20.430083 30294 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1124 01:07:20.431411 30294 replica.cpp:538] Replica received write request for position 2 from (6312)@172.17.18.107:37993
I1124 01:07:20.467258 30294 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 35.661978ms
I1124 01:07:20.467342 30294 replica.cpp:713] Persisted action at 2
I1124 01:07:20.468842 30290 replica.cpp:692] Replica received learned notice for position 2 from @0.0.0.0:0
I1124 01:07:20.502264 30290 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 33.367074ms
I1124 01:07:20.502426 30290 leveldb.cpp:399] Deleting ~1 keys from leveldb took 80765ns
I1124 01:07:20.502452 30290 replica.cpp:713] Persisted action at 2
I1124 01:07:20.502488 30290 replica.cpp:698] Replica learned TRUNCATE action at position 2
I1124 01:07:20.510509 30260 containerizer.cpp:141] Using isolation: posix/cpu,posix/mem,filesystem/posix
W1124 01:07:20.511119 30260 backend.cpp:48] Failed to create 'bind' backend: BindBackend requires root privileges
I1124 01:07:20.516801 30288 slave.cpp:189] Slave started on 219)@172.17.18.107:37993
I1124 01:07:20.516839 30288 slave.cpp:190] Flags at startup: --appc_store_dir="/tmp/mesos/store/appc" --authenticatee="crammd5" --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/ReservationEndpointsTest_UnreserveAvailableAndOfferedResources_CSzecr/credential" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_auth_server="auth.docker.io" --docker_auth_server_port="443" --docker_kill_orphans="true" --docker_local_archives_dir="/tmp/mesos/images/docker" --docker_puller="local" --docker_puller_timeout="60" --docker_registry="registry-1.docker.io" --docker_registry_port="443" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ReservationEndpointsTest_UnreserveAvailableAndOfferedResources_CSzecr/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher_dir="/mesos/mesos-0.26.0/_build/src" --logbufsecs="0" --logging_level="INFO" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:2;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/ReservationEndpointsTest_UnreserveAvailableAndOfferedResources_CSzecr"
I1124 01:07:20.517670 30288 credentials.hpp:83] Loading credential for authentication from '/tmp/ReservationEndpointsTest_UnreserveAvailableAndOfferedResources_CSzecr/credential'
I1124 01:07:20.517982 30288 slave.cpp:320] Slave using credential for: test-principal
I1124 01:07:20.518334 30288 resources.cpp:472] Parsing resources as JSON failed: cpus:2;mem:1024;disk:1024;ports:[31000-32000]
Trying semicolon-delimited string format instead
I1124 01:07:20.518815 30260 resources.cpp:472] Parsing resources as JSON failed: cpus:1;mem:128
Trying semicolon-delimited string format instead
I1124 01:07:20.518975 30288 slave.cpp:390] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1124 01:07:20.519104 30288 slave.cpp:398] Slave attributes: [  ]
I1124 01:07:20.519124 30288 slave.cpp:403] Slave hostname: 9f2f81738d5e
I1124 01:07:20.519136 30288 slave.cpp:408] Slave checkpoint: true
I1124 01:07:20.519407 30260 resources.cpp:472] Parsing resources as JSON failed: mem:384
Trying semicolon-delimited string format instead
I1124 01:07:20.522702 30288 state.cpp:52] Recovering state from '/tmp/ReservationEndpointsTest_UnreserveAvailableAndOfferedResources_CSzecr/meta'
I1124 01:07:20.523265 30288 status_update_manager.cpp:200] Recovering status update manager
I1124 01:07:20.523531 30288 containerizer.cpp:383] Recovering containerizer
I1124 01:07:20.524998 30288 slave.cpp:4258] Finished recovery
I1124 01:07:20.525802 30288 slave.cpp:4430] Querying resource estimator for oversubscribable resources
I1124 01:07:20.526753 30288 slave.cpp:727] New master detected at master@172.17.18.107:37993
I1124 01:07:20.527292 30288 slave.cpp:790] Authenticating with master master@172.17.18.107:37993
I1124 01:07:20.528240 30288 slave.cpp:795] Using default CRAM-MD5 authenticatee
I1124 01:07:20.527003 30286 status_update_manager.cpp:174] Pausing sending status updates
I1124 01:07:20.528955 30285 authenticatee.cpp:121] Creating new client SASL connection
I1124 01:07:20.529469 30285 master.cpp:5169] Authenticating slave(219)@172.17.18.107:37993
I1124 01:07:20.529729 30283 authenticator.cpp:413] Starting authentication session for crammd5_authenticatee(515)@172.17.18.107:37993
I1124 01:07:20.530287 30283 authenticator.cpp:98] Creating new server SASL connection
I1124 01:07:20.530764 30285 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
I1124 01:07:20.530903 30285 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I1124 01:07:20.531096 30285 authenticator.cpp:203] Received SASL authentication start
I1124 01:07:20.531241 30285 authenticator.cpp:325] Authentication requires more steps
I1124 01:07:20.531388 30285 authenticatee.cpp:258] Received SASL authentication step
I1124 01:07:20.531616 30285 authenticator.cpp:231] Received SASL authentication step
I1124 01:07:20.531668 30285 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: '9f2f81738d5e' server FQDN: '9f2f81738d5e' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I1124 01:07:20.531690 30285 auxprop.cpp:179] Looking up auxiliary property '*userPassword'
I1124 01:07:20.531774 30285 auxprop.cpp:179] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1124 01:07:20.531834 30285 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: '9f2f81738d5e' server FQDN: '9f2f81738d5e' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I1124 01:07:20.531855 30285 auxprop.cpp:129] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1124 01:07:20.531867 30285 auxprop.cpp:129] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1124 01:07:20.531903 30285 authenticator.cpp:317] Authentication success
I1124 01:07:20.532016 30283 authenticatee.cpp:298] Authentication success
I1124 01:07:20.532331 30281 master.cpp:5199] Successfully authenticated principal 'test-principal' at slave(219)@172.17.18.107:37993
I1124 01:07:20.532652 30291 authenticator.cpp:431] Authentication session cleanup for crammd5_authenticatee(515)@172.17.18.107:37993
I1124 01:07:20.533113 30288 slave.cpp:763] Detecting new master
I1124 01:07:20.533628 30288 slave.cpp:4444] Received oversubscribable resources  from the resource estimator
I1124 01:07:20.546396 30288 slave.cpp:858] Successfully authenticated with master master@172.17.18.107:37993
I1124 01:07:20.547111 30287 master.cpp:3878] Registering slave at slave(219)@172.17.18.107:37993 (9f2f81738d5e) with id ad27bc60-16d1-4239-9a65-235a991f9600-S0
I1124 01:07:20.547886 30287 registrar.cpp:439] Applied 1 operations in 91121ns; attempting to update the 'registry'
I1124 01:07:20.550647 30287 log.cpp:683] Attempting to append 347 bytes to the log
I1124 01:07:20.550935 30279 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3
I1124 01:07:20.551534 30288 slave.cpp:1252] Will retry registration in 3.399312ms if necessary
I1124 01:07:20.551868 30291 replica.cpp:538] Replica received write request for position 3 from (6324)@172.17.18.107:37993
I1124 01:07:20.557605 30281 slave.cpp:1252] Will retry registration in 16.296866ms if necessary
I1124 01:07:20.557891 30293 master.cpp:3866] Ignoring register slave message from slave(219)@172.17.18.107:37993 (9f2f81738d5e) as admission is already in progress
I1124 01:07:20.574681 30279 slave.cpp:1252] Will retry registration in 73.52632ms if necessary
I1124 01:07:20.575078 30293 master.cpp:3866] Ignoring register slave message from slave(219)@172.17.18.107:37993 (9f2f81738d5e) as admission is already in progress
I1124 01:07:20.586236 30291 leveldb.cpp:341] Persisting action (366 bytes) to leveldb took 34.301173ms
I1124 01:07:20.586287 30291 replica.cpp:713] Persisted action at 3
I1124 01:07:20.587509 30289 replica.cpp:692] Replica received learned notice for position 3 from @0.0.0.0:0
I1124 01:07:20.611263 30289 leveldb.cpp:341] Persisting action (368 bytes) to leveldb took 23.677211ms
I1124 01:07:20.611352 30289 replica.cpp:713] Persisted action at 3
I1124 01:07:20.611387 30289 replica.cpp:698] Replica learned APPEND action at position 3
I1124 01:07:20.613580 30279 registrar.cpp:484] Successfully updated the 'registry' in 65.490944ms
I1124 01:07:20.613802 30288 log.cpp:702] Attempting to truncate the log to 3
I1124 01:07:20.613993 30288 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 4
I1124 01:07:20.615281 30289 replica.cpp:538] Replica received write request for position 4 from (6325)@172.17.18.107:37993
I1124 01:07:20.615883 30279 master.cpp:3946] Registered slave ad27bc60-16d1-4239-9a65-235a991f9600-S0 at slave(219)@172.17.18.107:37993 (9f2f81738d5e) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1124 01:07:20.616261 30282 slave.cpp:902] Registered with master master@172.17.18.107:37993; given slave ID ad27bc60-16d1-4239-9a65-235a991f9600-S0
I1124 01:07:20.616883 30282 fetcher.cpp:79] Clearing fetcher cache
I1124 01:07:20.617261 30280 status_update_manager.cpp:181] Resuming sending status updates
I1124 01:07:20.617766 30282 slave.cpp:925] Checkpointing SlaveInfo to '/tmp/ReservationEndpointsTest_UnreserveAvailableAndOfferedResources_CSzecr/meta/slaves/ad27bc60-16d1-4239-9a65-235a991f9600-S0/slave.info'
I1124 01:07:20.616550 30284 hierarchical.cpp:380] Added slave ad27bc60-16d1-4239-9a65-235a991f9600-S0 (9f2f81738d5e) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: )
I1124 01:07:20.618670 30282 slave.cpp:961] Forwarding total oversubscribed resources 
I1124 01:07:20.618932 30282 slave.cpp:3197] Received ping from slave-observer(216)@172.17.18.107:37993
I1124 01:07:20.619288 30285 master.cpp:4288] Received update of slave ad27bc60-16d1-4239-9a65-235a991f9600-S0 at slave(219)@172.17.18.107:37993 (9f2f81738d5e) with total oversubscribed resources 
I1124 01:07:20.619446 30284 hierarchical.cpp:1066] No resources available to allocate!
I1124 01:07:20.619526 30284 hierarchical.cpp:1159] No inverse offers to send out!
I1124 01:07:20.619568 30284 hierarchical.cpp:977] Performed allocation for slave ad27bc60-16d1-4239-9a65-235a991f9600-S0 in 1.108641ms
I1124 01:07:20.620057 30284 hierarchical.cpp:436] Slave ad27bc60-16d1-4239-9a65-235a991f9600-S0 (9f2f81738d5e) updated with oversubscribed resources  (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: )
I1124 01:07:20.620393 30284 hierarchical.cpp:1066] No resources available to allocate!
I1124 01:07:20.620462 30284 hierarchical.cpp:1159] No inverse offers to send out!
I1124 01:07:20.620507 30284 hierarchical.cpp:977] Performed allocation for slave ad27bc60-16d1-4239-9a65-235a991f9600-S0 in 395959ns
I1124 01:07:20.624356 30285 process.cpp:3067] Handling HTTP event for process 'master' with path: '/master/reserve'
I1124 01:07:20.624418 30285 http.cpp:336] HTTP POST for /master/reserve from 172.17.18.107:48995
I1124 01:07:20.626936 30285 master.cpp:6224] Sending checkpointed resources cpus(role, test-principal):1; mem(role, test-principal):512 to slave ad27bc60-16d1-4239-9a65-235a991f9600-S0 at slave(219)@172.17.18.107:37993 (9f2f81738d5e)
I1124 01:07:20.631428 30260 sched.cpp:164] Version: 0.26.0
I1124 01:07:20.632068 30287 sched.cpp:262] New master detected at master@172.17.18.107:37993
I1124 01:07:20.632230 30287 sched.cpp:318] Authenticating with master master@172.17.18.107:37993
I1124 01:07:20.632307 30287 sched.cpp:325] Using default CRAM-MD5 authenticatee
I1124 01:07:20.632693 30287 authenticatee.cpp:121] Creating new client SASL connection
I1124 01:07:20.633275 30287 master.cpp:5169] Authenticating scheduler-2c19aed9-7470-4927-949b-fb23f1775ab4@172.17.18.107:37993
I1124 01:07:20.633519 30287 authenticator.cpp:413] Starting authentication session for crammd5_authenticatee(516)@172.17.18.107:37993
I1124 01:07:20.633965 30287 authenticator.cpp:98] Creating new server SASL connection
I1124 01:07:20.634316 30287 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
I1124 01:07:20.634456 30287 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I1124 01:07:20.634605 30287 authenticator.cpp:203] Received SASL authentication start
I1124 01:07:20.634771 30287 authenticator.cpp:325] Authentication requires more steps
I1124 01:07:20.634914 30287 authenticatee.cpp:258] Received SASL authentication step
I1124 01:07:20.635126 30287 authenticator.cpp:231] Received SASL authentication step
I1124 01:07:20.635270 30287 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: '9f2f81738d5e' server FQDN: '9f2f81738d5e' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I1124 01:07:20.635347 30287 auxprop.cpp:179] Looking up auxiliary property '*userPassword'
I1124 01:07:20.636262 30287 auxprop.cpp:179] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1124 01:07:20.636349 30287 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: '9f2f81738d5e' server FQDN: '9f2f81738d5e' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I1124 01:07:20.636415 30287 auxprop.cpp:129] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1124 01:07:20.636466 30287 auxprop.cpp:129] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1124 01:07:20.636541 30287 authenticator.cpp:317] Authentication success
I1124 01:07:20.636754 30287 authenticatee.cpp:298] Authentication success
I1124 01:07:20.636831 30286 master.cpp:5199] Successfully authenticated principal 'test-principal' at scheduler-2c19aed9-7470-4927-949b-fb23f1775ab4@172.17.18.107:37993
I1124 01:07:20.636884 30281 authenticator.cpp:431] Authentication session cleanup for crammd5_authenticatee(516)@172.17.18.107:37993
I1124 01:07:20.637516 30286 sched.cpp:407] Successfully authenticated with master master@172.17.18.107:37993
I1124 01:07:20.637622 30286 sched.cpp:714] Sending SUBSCRIBE call to master@172.17.18.107:37993
I1124 01:07:20.637763 30286 sched.cpp:747] Will retry registration in 1.659715229secs if necessary
I1124 01:07:20.637928 30280 master.cpp:2195] Received SUBSCRIBE call for framework 'default' at scheduler-2c19aed9-7470-4927-949b-fb23f1775ab4@172.17.18.107:37993
I1124 01:07:20.638162 30280 master.cpp:1664] Authorizing framework principal 'test-principal' to receive offers for role 'role'
I1124 01:07:20.638510 30280 master.cpp:2266] Subscribing framework default with checkpointing disabled and capabilities [  ]
I1124 01:07:20.639348 30283 sched.cpp:641] Framework registered with ad27bc60-16d1-4239-9a65-235a991f9600-0000
I1124 01:07:20.639452 30283 sched.cpp:655] Scheduler::registered took 18594ns
I1124 01:07:20.639559 30280 hierarchical.cpp:220] Added framework ad27bc60-16d1-4239-9a65-235a991f9600-0000
I1124 01:07:20.640575 30280 hierarchical.cpp:1159] No inverse offers to send out!
I1124 01:07:20.641254 30280 hierarchical.cpp:961] Performed allocation for 1 slaves in 1.618341ms
I1124 01:07:20.641125 30283 master.cpp:4998] Sending 1 offers to framework ad27bc60-16d1-4239-9a65-235a991f9600-0000 (default) at scheduler-2c19aed9-7470-4927-949b-fb23f1775ab4@172.17.18.107:37993

GMOCK WARNING:
Uninteresting mock function call - returning directly.
    Function call: resourceOffers(0x7fffe27c3830, @0x2ae03c9ce9d0 { 144-byte object <D0-1C B2-33 E0-2A 00-00 00-00 00-00 00-00 00-00 70-CF 00-48 E0-2A 00-00 10-D0 00-48 E0-2A 00-00 B0-D0 00-48 E0-2A 00-00 50-D1 00-48 E0-2A 00-00 A0-D1 00-48 E0-2A 00-00 40-00 01-48 E0-2A 00-00 ... 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 35-61 39-39 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 63-36 30-2D 00-00 00-00 00-00 00-00 00-00 00-00 1F-00 00-00> })
Stack trace:
I1124 01:07:20.642010 30283 sched.cpp:811] Scheduler::resourceOffers took 257483ns
I1124 01:07:20.642578 30283 master.cpp:3395] Processing REVIVE call for framework ad27bc60-16d1-4239-9a65-235a991f9600-0000 (default) at scheduler-2c19aed9-7470-4927-949b-fb23f1775ab4@172.17.18.107:37993
I1124 01:07:20.642757 30283 hierarchical.cpp:886] Removed offer filters for framework ad27bc60-16d1-4239-9a65-235a991f9600-0000
I1124 01:07:20.644323 30283 hierarchical.cpp:1066] No resources available to allocate!
I1124 01:07:20.644377 30283 hierarchical.cpp:1159] No inverse offers to send out!
I1124 01:07:20.644404 30283 hierarchical.cpp:961] Performed allocation for 1 slaves in 1.616762ms
I1124 01:07:20.644626 30291 slave.cpp:2275] Updated checkpointed resources from  to cpus(role, test-principal):1; mem(role, test-principal):512
I1124 01:07:20.652545 30289 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 37.216951ms
I1124 01:07:20.652601 30289 replica.cpp:713] Persisted action at 4
I1124 01:07:20.667095 30279 replica.cpp:692] Replica received learned notice for position 4 from @0.0.0.0:0
I1124 01:07:20.695262 30279 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 28.08901ms
I1124 01:07:20.695446 30279 leveldb.cpp:399] Deleting ~2 keys from leveldb took 96033ns
I1124 01:07:20.695482 30279 replica.cpp:713] Persisted action at 4
I1124 01:07:20.695523 30279 replica.cpp:698] Replica learned TRUNCATE action at position 4
2015-11-24 01:07:21,415:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:07:24,751:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:07:28,087:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:07:31,424:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:07:34,760:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I1124 01:07:35.534328 30283 slave.cpp:4430] Querying resource estimator for oversubscribable resources
I1124 01:07:35.534613 30283 slave.cpp:4444] Received oversubscribable resources  from the resource estimator
I1124 01:07:35.616957 30293 slave.cpp:3197] Received ping from slave-observer(216)@172.17.18.107:37993
2015-11-24 01:07:38,096:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:07:41,433:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:07:44,769:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:07:48,105:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I1124 01:07:50.535526 30284 slave.cpp:4430] Querying resource estimator for oversubscribable resources
I1124 01:07:50.535809 30284 slave.cpp:4444] Received oversubscribable resources  from the resource estimator
I1124 01:07:50.618424 30284 slave.cpp:3197] Received ping from slave-observer(216)@172.17.18.107:37993
2015-11-24 01:07:51,441:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:07:54,778:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:07:58,114:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:08:01,450:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:08:04,785:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I1124 01:08:05.536947 30293 slave.cpp:4430] Querying resource estimator for oversubscribable resources
I1124 01:08:05.537225 30293 slave.cpp:4444] Received oversubscribable resources  from the resource estimator
I1124 01:08:05.619575 30293 slave.cpp:3197] Received ping from slave-observer(216)@172.17.18.107:37993
2015-11-24 01:08:08,119:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:08:11,456:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:08:14,790:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:08:18,127:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I1124 01:08:20.520412 30280 slave.cpp:4067] Current disk usage 6.86%. Max allowed age: 5.820034363201435days
I1124 01:08:20.539533 30289 slave.cpp:4430] Querying resource estimator for oversubscribable resources
I1124 01:08:20.539852 30289 slave.cpp:4444] Received oversubscribable resources  from the resource estimator
I1124 01:08:20.620409 30284 slave.cpp:3197] Received ping from slave-observer(216)@172.17.18.107:37993
2015-11-24 01:08:21,463:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:08:24,799:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:08:28,135:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:08:31,471:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:08:34,807:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I1124 01:08:35.540747 30288 slave.cpp:4430] Querying resource estimator for oversubscribable resources
I1124 01:08:35.541132 30288 slave.cpp:4444] Received oversubscribable resources  from the resource estimator
I1124 01:08:35.621484 30287 slave.cpp:3197] Received ping from slave-observer(216)@172.17.18.107:37993
2015-11-24 01:08:38,143:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:08:41,479:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:08:44,815:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:08:48,152:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I1124 01:08:50.543668 30280 slave.cpp:4430] Querying resource estimator for oversubscribable resources
I1124 01:08:50.544008 30280 slave.cpp:4444] Received oversubscribable resources  from the resource estimator
I1124 01:08:50.622236 30287 slave.cpp:3197] Received ping from slave-observer(216)@172.17.18.107:37993
2015-11-24 01:08:51,488:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:08:54,824:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24 01:08:58,160:30260(0x2ae0d6471700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:46930] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
2015-11-24
.... (more lines of similar logs)

Logs from a good run:

[ RUN      ] ReservationEndpointsTest.UnreserveAvailableAndOfferedResources
I1124 14:31:32.379406 30274 leveldb.cpp:174] Opened db in 3.209566ms
I1124 14:31:32.380513 30274 leveldb.cpp:181] Compacted db in 1.056579ms
I1124 14:31:32.380601 30274 leveldb.cpp:196] Created db iterator in 26511ns
I1124 14:31:32.380617 30274 leveldb.cpp:202] Seeked to beginning of db in 1855ns
I1124 14:31:32.380625 30274 leveldb.cpp:271] Iterated through 0 keys in the db in 390ns
I1124 14:31:32.380677 30274 replica.cpp:778] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1124 14:31:32.381772 30304 recover.cpp:447] Starting replica recovery
I1124 14:31:32.382041 30304 recover.cpp:473] Replica is in EMPTY status
I1124 14:31:32.383296 30303 replica.cpp:674] Replica in EMPTY status received a broadcasted recover request from (6249)@172.17.6.149:52680
I1124 14:31:32.383708 30298 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1124 14:31:32.384263 30305 recover.cpp:564] Updating replica status to STARTING
I1124 14:31:32.384837 30303 master.cpp:365] Master 540f518e-1ba4-4f89-8b15-7b99ef53c093 (c264cb162c79) started on 172.17.6.149:52680
I1124 14:31:32.384984 30304 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 591432ns
I1124 14:31:32.385017 30304 replica.cpp:321] Persisted replica status to STARTING
I1124 14:31:32.384865 30303 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1000secs" --allocator="HierarchicalDRF" --authenticate="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/L5EFJU/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --roles="role" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/L5EFJU/master" --zk_session_timeout="10secs"
I1124 14:31:32.385262 30303 master.cpp:412] Master only allowing authenticated frameworks to register
I1124 14:31:32.385279 30303 master.cpp:417] Master only allowing authenticated slaves to register
I1124 14:31:32.385288 30303 credentials.hpp:35] Loading credentials for authentication from '/tmp/L5EFJU/credentials'
I1124 14:31:32.385319 30297 recover.cpp:473] Replica is in STARTING status
I1124 14:31:32.385628 30303 master.cpp:456] Using default 'crammd5' authenticator
I1124 14:31:32.385783 30303 master.cpp:493] Authorization enabled
I1124 14:31:32.386221 30299 whitelist_watcher.cpp:77] No whitelist given
I1124 14:31:32.386329 30302 hierarchical.cpp:162] Initialized hierarchical allocator process
I1124 14:31:32.386343 30299 replica.cpp:674] Replica in STARTING status received a broadcasted recover request from (6250)@172.17.6.149:52680
I1124 14:31:32.386756 30308 recover.cpp:193] Received a recover response from a replica in STARTING status
I1124 14:31:32.387285 30305 recover.cpp:564] Updating replica status to VOTING
I1124 14:31:32.388052 30293 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 444555ns
I1124 14:31:32.388090 30293 replica.cpp:321] Persisted replica status to VOTING
I1124 14:31:32.388299 30300 recover.cpp:578] Successfully joined the Paxos group
I1124 14:31:32.388371 30308 master.cpp:1625] The newly elected leader is master@172.17.6.149:52680 with id 540f518e-1ba4-4f89-8b15-7b99ef53c093
I1124 14:31:32.388417 30308 master.cpp:1638] Elected as the leading master!
I1124 14:31:32.388442 30308 master.cpp:1383] Recovering from registrar
I1124 14:31:32.388593 30305 registrar.cpp:307] Recovering registrar
I1124 14:31:32.388627 30300 recover.cpp:462] Recover process terminated
I1124 14:31:32.389482 30294 log.cpp:659] Attempting to start the writer
I1124 14:31:32.390638 30294 replica.cpp:494] Replica received implicit promise request from (6251)@172.17.6.149:52680 with proposal 1
I1124 14:31:32.391034 30294 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 365035ns
I1124 14:31:32.391055 30294 replica.cpp:343] Persisted promised to 1
I1124 14:31:32.391635 30297 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1124 14:31:32.392724 30305 replica.cpp:389] Replica received explicit promise request from (6252)@172.17.6.149:52680 for position 0 with proposal 2
I1124 14:31:32.393254 30305 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 490425ns
I1124 14:31:32.393277 30305 replica.cpp:713] Persisted action at 0
I1124 14:31:32.394223 30305 replica.cpp:538] Replica received write request for position 0 from (6253)@172.17.6.149:52680
I1124 14:31:32.394282 30305 leveldb.cpp:436] Reading position from leveldb took 29241ns
I1124 14:31:32.394809 30305 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 477617ns
I1124 14:31:32.394830 30305 replica.cpp:713] Persisted action at 0
I1124 14:31:32.395393 30307 replica.cpp:692] Replica received learned notice for position 0 from @0.0.0.0:0
I1124 14:31:32.395923 30307 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 499295ns
I1124 14:31:32.395946 30307 replica.cpp:713] Persisted action at 0
I1124 14:31:32.395979 30307 replica.cpp:698] Replica learned NOP action at position 0
I1124 14:31:32.396602 30304 log.cpp:675] Writer started with ending position 0
I1124 14:31:32.397611 30298 leveldb.cpp:436] Reading position from leveldb took 29312ns
I1124 14:31:32.398551 30297 registrar.cpp:340] Successfully fetched the registry (0B) in 9.914112ms
I1124 14:31:32.398671 30297 registrar.cpp:439] Applied 1 operations in 29912ns; attempting to update the 'registry'
I1124 14:31:32.399397 30296 log.cpp:683] Attempting to append 176 bytes to the log
I1124 14:31:32.399523 30302 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1124 14:31:32.400318 30304 replica.cpp:538] Replica received write request for position 1 from (6254)@172.17.6.149:52680
I1124 14:31:32.400794 30304 leveldb.cpp:341] Persisting action (195 bytes) to leveldb took 416219ns
I1124 14:31:32.400825 30304 replica.cpp:713] Persisted action at 1
I1124 14:31:32.401752 30307 replica.cpp:692] Replica received learned notice for position 1 from @0.0.0.0:0
I1124 14:31:32.402163 30307 leveldb.cpp:341] Persisting action (197 bytes) to leveldb took 367685ns
I1124 14:31:32.402194 30307 replica.cpp:713] Persisted action at 1
I1124 14:31:32.402217 30307 replica.cpp:698] Replica learned APPEND action at position 1
I1124 14:31:32.403475 30301 registrar.cpp:484] Successfully updated the 'registry' in 4.722944ms
I1124 14:31:32.403673 30301 registrar.cpp:370] Successfully recovered registrar
I1124 14:31:32.403895 30297 log.cpp:702] Attempting to truncate the log to 1
I1124 14:31:32.404165 30293 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1124 14:31:32.404492 30307 master.cpp:1435] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
I1124 14:31:32.404580 30306 hierarchical.cpp:174] Allocator recovery is not supported yet
I1124 14:31:32.405313 30307 replica.cpp:538] Replica received write request for position 2 from (6255)@172.17.6.149:52680
I1124 14:31:32.405725 30307 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 369717ns
I1124 14:31:32.405756 30307 replica.cpp:713] Persisted action at 2
I1124 14:31:32.406597 30303 replica.cpp:692] Replica received learned notice for position 2 from @0.0.0.0:0
I1124 14:31:32.407234 30303 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 590194ns
I1124 14:31:32.407291 30303 leveldb.cpp:399] Deleting ~1 keys from leveldb took 31709ns
I1124 14:31:32.407313 30303 replica.cpp:713] Persisted action at 2
I1124 14:31:32.407346 30303 replica.cpp:698] Replica learned TRUNCATE action at position 2
I1124 14:31:32.417404 30274 containerizer.cpp:141] Using isolation: posix/cpu,posix/mem,filesystem/posix
W1124 14:31:32.417768 30274 backend.cpp:48] Failed to create 'bind' backend: BindBackend requires root privileges
I1124 14:31:32.420657 30300 slave.cpp:189] Slave started on 219)@172.17.6.149:52680
I1124 14:31:32.420680 30300 slave.cpp:190] Flags at startup: --appc_store_dir="/tmp/mesos/store/appc" --authenticatee="crammd5" --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/ReservationEndpointsTest_UnreserveAvailableAndOfferedResources_N4vdsa/credential" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_auth_server="auth.docker.io" --docker_auth_server_port="443" --docker_kill_orphans="true" --docker_local_archives_dir="/tmp/mesos/images/docker" --docker_puller="local" --docker_puller_timeout="60" --docker_registry="registry-1.docker.io" --docker_registry_port="443" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ReservationEndpointsTest_UnreserveAvailableAndOfferedResources_N4vdsa/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher_dir="/mesos/mesos-0.27.0/_build/src" --logbufsecs="0" --logging_level="INFO" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:2;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/ReservationEndpointsTest_UnreserveAvailableAndOfferedResources_N4vdsa"
I1124 14:31:32.421241 30300 credentials.hpp:83] Loading credential for authentication from '/tmp/ReservationEndpointsTest_UnreserveAvailableAndOfferedResources_N4vdsa/credential'
I1124 14:31:32.421465 30300 slave.cpp:320] Slave using credential for: test-principal
I1124 14:31:32.421685 30300 resources.cpp:472] Parsing resources as JSON failed: cpus:2;mem:1024;disk:1024;ports:[31000-32000]
Trying semicolon-delimited string format instead
I1124 14:31:32.422097 30300 slave.cpp:390] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1124 14:31:32.422158 30300 slave.cpp:398] Slave attributes: [  ]
I1124 14:31:32.422168 30300 slave.cpp:403] Slave hostname: c264cb162c79
I1124 14:31:32.422163 30274 resources.cpp:472] Parsing resources as JSON failed: cpus:1;mem:128
Trying semicolon-delimited string format instead
I1124 14:31:32.422174 30300 slave.cpp:408] Slave checkpoint: true
I1124 14:31:32.422358 30274 resources.cpp:472] Parsing resources as JSON failed: mem:384
Trying semicolon-delimited string format instead
I1124 14:31:32.423035 30299 state.cpp:52] Recovering state from '/tmp/ReservationEndpointsTest_UnreserveAvailableAndOfferedResources_N4vdsa/meta'
I1124 14:31:32.423334 30294 status_update_manager.cpp:200] Recovering status update manager
I1124 14:31:32.423507 30300 containerizer.cpp:383] Recovering containerizer
I1124 14:31:32.424350 30296 slave.cpp:4258] Finished recovery
I1124 14:31:32.424875 30296 slave.cpp:4430] Querying resource estimator for oversubscribable resources
I1124 14:31:32.425091 30297 status_update_manager.cpp:174] Pausing sending status updates
I1124 14:31:32.425112 30296 slave.cpp:727] New master detected at master@172.17.6.149:52680
I1124 14:31:32.425194 30296 slave.cpp:790] Authenticating with master master@172.17.6.149:52680
I1124 14:31:32.425214 30296 slave.cpp:795] Using default CRAM-MD5 authenticatee
I1124 14:31:32.425395 30296 slave.cpp:763] Detecting new master
I1124 14:31:32.425431 30305 authenticatee.cpp:121] Creating new client SASL connection
I1124 14:31:32.425519 30296 slave.cpp:4444] Received oversubscribable resources  from the resource estimator
I1124 14:31:32.425684 30301 master.cpp:5169] Authenticating slave(219)@172.17.6.149:52680
I1124 14:31:32.425815 30293 authenticator.cpp:413] Starting authentication session for crammd5_authenticatee(513)@172.17.6.149:52680
I1124 14:31:32.426038 30296 authenticator.cpp:98] Creating new server SASL connection
I1124 14:31:32.426308 30305 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
I1124 14:31:32.426344 30305 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I1124 14:31:32.426435 30305 authenticator.cpp:203] Received SASL authentication start
I1124 14:31:32.426487 30305 authenticator.cpp:325] Authentication requires more steps
I1124 14:31:32.426573 30305 authenticatee.cpp:258] Received SASL authentication step
I1124 14:31:32.426687 30302 authenticator.cpp:231] Received SASL authentication step
I1124 14:31:32.426719 30302 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: 'c264cb162c79' server FQDN: 'c264cb162c79' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I1124 14:31:32.426733 30302 auxprop.cpp:179] Looking up auxiliary property '*userPassword'
I1124 14:31:32.426770 30302 auxprop.cpp:179] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1124 14:31:32.426789 30302 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: 'c264cb162c79' server FQDN: 'c264cb162c79' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I1124 14:31:32.426797 30302 auxprop.cpp:129] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1124 14:31:32.426803 30302 auxprop.cpp:129] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1124 14:31:32.426815 30302 authenticator.cpp:317] Authentication success
I1124 14:31:32.426888 30299 authenticatee.cpp:298] Authentication success
I1124 14:31:32.426975 30307 master.cpp:5199] Successfully authenticated principal 'test-principal' at slave(219)@172.17.6.149:52680
I1124 14:31:32.427198 30308 authenticator.cpp:431] Authentication session cleanup for crammd5_authenticatee(513)@172.17.6.149:52680
I1124 14:31:32.427345 30299 slave.cpp:858] Successfully authenticated with master master@172.17.6.149:52680
I1124 14:31:32.427480 30299 slave.cpp:1252] Will retry registration in 14.843642ms if necessary
I1124 14:31:32.427793 30298 master.cpp:3878] Registering slave at slave(219)@172.17.6.149:52680 (c264cb162c79) with id 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0
I1124 14:31:32.428304 30301 registrar.cpp:439] Applied 1 operations in 66689ns; attempting to update the 'registry'
I1124 14:31:32.429102 30296 log.cpp:683] Attempting to append 345 bytes to the log
I1124 14:31:32.429255 30301 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3
I1124 14:31:32.429944 30305 replica.cpp:538] Replica received write request for position 3 from (6267)@172.17.6.149:52680
I1124 14:31:32.430567 30305 leveldb.cpp:341] Persisting action (364 bytes) to leveldb took 565035ns
I1124 14:31:32.430591 30305 replica.cpp:713] Persisted action at 3
I1124 14:31:32.431191 30301 replica.cpp:692] Replica received learned notice for position 3 from @0.0.0.0:0
I1124 14:31:32.431586 30301 leveldb.cpp:341] Persisting action (366 bytes) to leveldb took 363559ns
I1124 14:31:32.431609 30301 replica.cpp:713] Persisted action at 3
I1124 14:31:32.431627 30301 replica.cpp:698] Replica learned APPEND action at position 3
2015-11-24 14:31:32,432:30274(0x2b7afc200700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:34475] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I1124 14:31:32.433154 30296 registrar.cpp:484] Successfully updated the 'registry' in 4.772864ms
I1124 14:31:32.433446 30300 log.cpp:702] Attempting to truncate the log to 3
I1124 14:31:32.433552 30294 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 4
I1124 14:31:32.434074 30295 slave.cpp:3197] Received ping from slave-observer(219)@172.17.6.149:52680
I1124 14:31:32.434813 30302 hierarchical.cpp:380] Added slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 (c264cb162c79) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: )
I1124 14:31:32.435241 30302 hierarchical.cpp:1066] No resources available to allocate!
I1124 14:31:32.435408 30302 hierarchical.cpp:1159] No inverse offers to send out!
I1124 14:31:32.435560 30302 hierarchical.cpp:977] Performed allocation for slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 in 687663ns
I1124 14:31:32.435897 30304 replica.cpp:538] Replica received write request for position 4 from (6268)@172.17.6.149:52680
I1124 14:31:32.435978 30306 master.cpp:3946] Registered slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 at slave(219)@172.17.6.149:52680 (c264cb162c79) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1124 14:31:32.436049 30294 slave.cpp:902] Registered with master master@172.17.6.149:52680; given slave ID 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0
I1124 14:31:32.436082 30294 fetcher.cpp:79] Clearing fetcher cache
I1124 14:31:32.436264 30300 status_update_manager.cpp:181] Resuming sending status updates
I1124 14:31:32.436611 30294 slave.cpp:925] Checkpointing SlaveInfo to '/tmp/ReservationEndpointsTest_UnreserveAvailableAndOfferedResources_N4vdsa/meta/slaves/540f518e-1ba4-4f89-8b15-7b99ef53c093-S0/slave.info'
I1124 14:31:32.437463 30294 slave.cpp:961] Forwarding total oversubscribed resources 
I1124 14:31:32.437489 30304 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 1.540024ms
I1124 14:31:32.437528 30304 replica.cpp:713] Persisted action at 4
I1124 14:31:32.437707 30293 process.cpp:3067] Handling HTTP event for process 'master' with path: '/master/reserve'
I1124 14:31:32.437942 30293 http.cpp:336] HTTP POST for /master/reserve from 172.17.6.149:46929
I1124 14:31:32.438607 30294 replica.cpp:692] Replica received learned notice for position 4 from @0.0.0.0:0
I1124 14:31:32.439095 30294 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 443410ns
I1124 14:31:32.439173 30294 leveldb.cpp:399] Deleting ~2 keys from leveldb took 47749ns
I1124 14:31:32.439280 30294 replica.cpp:713] Persisted action at 4
I1124 14:31:32.439323 30294 replica.cpp:698] Replica learned TRUNCATE action at position 4
I1124 14:31:32.439617 30293 master.cpp:4288] Received update of slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 at slave(219)@172.17.6.149:52680 (c264cb162c79) with total oversubscribed resources 
I1124 14:31:32.440897 30294 master.cpp:6224] Sending checkpointed resources cpus(role, test-principal):1; mem(role, test-principal):512 to slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 at slave(219)@172.17.6.149:52680 (c264cb162c79)
I1124 14:31:32.441396 30298 hierarchical.cpp:436] Slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 (c264cb162c79) updated with oversubscribed resources  (total: cpus(*):1; mem(*):512; disk(*):1024; ports(*):[31000-32000]; cpus(role, test-principal):1; mem(role, test-principal):512, allocated: )
I1124 14:31:32.441532 30294 slave.cpp:2275] Updated checkpointed resources from  to cpus(role, test-principal):1; mem(role, test-principal):512
I1124 14:31:32.441783 30298 hierarchical.cpp:1066] No resources available to allocate!
I1124 14:31:32.441862 30298 hierarchical.cpp:1159] No inverse offers to send out!
I1124 14:31:32.441889 30298 hierarchical.cpp:977] Performed allocation for slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 in 427498ns
I1124 14:31:32.443641 30274 sched.cpp:164] Version: 0.27.0
I1124 14:31:32.444103 30303 sched.cpp:1261] Ignoring revive offers message as master is disconnected
I1124 14:31:32.444250 30304 sched.cpp:262] New master detected at master@172.17.6.149:52680
I1124 14:31:32.444331 30304 sched.cpp:318] Authenticating with master master@172.17.6.149:52680
I1124 14:31:32.444356 30304 sched.cpp:325] Using default CRAM-MD5 authenticatee
I1124 14:31:32.444573 30298 authenticatee.cpp:121] Creating new client SASL connection
I1124 14:31:32.444828 30297 master.cpp:5169] Authenticating scheduler-0ff32e9c-a0bb-4f1c-a2e6-580485a123be@172.17.6.149:52680
I1124 14:31:32.444926 30307 authenticator.cpp:413] Starting authentication session for crammd5_authenticatee(514)@172.17.6.149:52680
I1124 14:31:32.445137 30302 authenticator.cpp:98] Creating new server SASL connection
I1124 14:31:32.445329 30304 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
I1124 14:31:32.445359 30304 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I1124 14:31:32.445464 30294 authenticator.cpp:203] Received SASL authentication start
I1124 14:31:32.445531 30294 authenticator.cpp:325] Authentication requires more steps
I1124 14:31:32.445641 30304 authenticatee.cpp:258] Received SASL authentication step
I1124 14:31:32.445760 30294 authenticator.cpp:231] Received SASL authentication step
I1124 14:31:32.445794 30294 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: 'c264cb162c79' server FQDN: 'c264cb162c79' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I1124 14:31:32.445811 30294 auxprop.cpp:179] Looking up auxiliary property '*userPassword'
I1124 14:31:32.445849 30294 auxprop.cpp:179] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1124 14:31:32.445875 30294 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: 'c264cb162c79' server FQDN: 'c264cb162c79' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I1124 14:31:32.445885 30294 auxprop.cpp:129] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1124 14:31:32.445890 30294 auxprop.cpp:129] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1124 14:31:32.445904 30294 authenticator.cpp:317] Authentication success
I1124 14:31:32.446023 30303 authenticatee.cpp:298] Authentication success
I1124 14:31:32.446034 30308 master.cpp:5199] Successfully authenticated principal 'test-principal' at scheduler-0ff32e9c-a0bb-4f1c-a2e6-580485a123be@172.17.6.149:52680
I1124 14:31:32.446112 30302 authenticator.cpp:431] Authentication session cleanup for crammd5_authenticatee(514)@172.17.6.149:52680
I1124 14:31:32.446387 30299 sched.cpp:407] Successfully authenticated with master master@172.17.6.149:52680
I1124 14:31:32.446409 30299 sched.cpp:714] Sending SUBSCRIBE call to master@172.17.6.149:52680
I1124 14:31:32.446502 30299 sched.cpp:747] Will retry registration in 22.168105ms if necessary
I1124 14:31:32.446610 30308 master.cpp:2195] Received SUBSCRIBE call for framework 'default' at scheduler-0ff32e9c-a0bb-4f1c-a2e6-580485a123be@172.17.6.149:52680
I1124 14:31:32.446663 30308 master.cpp:1664] Authorizing framework principal 'test-principal' to receive offers for role 'role'
I1124 14:31:32.446889 30293 master.cpp:2266] Subscribing framework default with checkpointing disabled and capabilities [  ]
I1124 14:31:32.447237 30297 hierarchical.cpp:220] Added framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.447360 30304 sched.cpp:641] Framework registered with 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.447406 30304 sched.cpp:655] Scheduler::registered took 20613ns
I1124 14:31:32.448019 30297 hierarchical.cpp:1159] No inverse offers to send out!
I1124 14:31:32.448055 30297 hierarchical.cpp:961] Performed allocation for 1 slaves in 792842ns
I1124 14:31:32.448572 30294 master.cpp:4998] Sending 1 offers to framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 (default) at scheduler-0ff32e9c-a0bb-4f1c-a2e6-580485a123be@172.17.6.149:52680
I1124 14:31:32.449141 30293 sched.cpp:811] Scheduler::resourceOffers took 122685ns
I1124 14:31:32.451211 30305 master.cpp:2934] Processing ACCEPT call for offers: [ 540f518e-1ba4-4f89-8b15-7b99ef53c093-O0 ] on slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 at slave(219)@172.17.6.149:52680 (c264cb162c79) for framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 (default) at scheduler-0ff32e9c-a0bb-4f1c-a2e6-580485a123be@172.17.6.149:52680
I1124 14:31:32.451257 30305 master.cpp:2730] Authorizing framework principal 'test-principal' to launch task 981ca865-a5f9-42c6-8090-eaf909f78186 as user 'mesos'
I1124 14:31:32.452697 30296 master.hpp:176] Adding task 981ca865-a5f9-42c6-8090-eaf909f78186 with resources cpus(role, test-principal):1; mem(role, test-principal):128 on slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 (c264cb162c79)
I1124 14:31:32.452819 30296 master.cpp:3264] Launching task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 (default) at scheduler-0ff32e9c-a0bb-4f1c-a2e6-580485a123be@172.17.6.149:52680 with resources cpus(role, test-principal):1; mem(role, test-principal):128 on slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 at slave(219)@172.17.6.149:52680 (c264cb162c79)
I1124 14:31:32.453191 30305 slave.cpp:1292] Got assigned task 981ca865-a5f9-42c6-8090-eaf909f78186 for framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.453485 30305 resources.cpp:472] Parsing resources as JSON failed: cpus:0.1;mem:32
Trying semicolon-delimited string format instead
I1124 14:31:32.453652 30303 hierarchical.cpp:793] Recovered cpus(*):1; mem(*):512; disk(*):1024; ports(*):[31000-32000]; mem(role, test-principal):384 (total: cpus(*):1; mem(*):512; disk(*):1024; ports(*):[31000-32000]; cpus(role, test-principal):1; mem(role, test-principal):512, allocated: cpus(role, test-principal):1; mem(role, test-principal):128) on slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 from framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.453729 30303 hierarchical.cpp:830] Framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 filtered slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 for 5secs
I1124 14:31:32.454195 30305 slave.cpp:1411] Launching task 981ca865-a5f9-42c6-8090-eaf909f78186 for framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.454306 30305 resources.cpp:472] Parsing resources as JSON failed: cpus:0.1;mem:32
Trying semicolon-delimited string format instead
I1124 14:31:32.455086 30305 paths.cpp:434] Trying to chown '/tmp/ReservationEndpointsTest_UnreserveAvailableAndOfferedResources_N4vdsa/slaves/540f518e-1ba4-4f89-8b15-7b99ef53c093-S0/frameworks/540f518e-1ba4-4f89-8b15-7b99ef53c093-0000/executors/981ca865-a5f9-42c6-8090-eaf909f78186/runs/8544eb55-baa8-495a-98e7-565ec58da673' to user 'mesos'
I1124 14:31:32.462555 30305 slave.cpp:5043] Launching executor 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 with resources cpus(*):0.1; mem(*):32 in work directory '/tmp/ReservationEndpointsTest_UnreserveAvailableAndOfferedResources_N4vdsa/slaves/540f518e-1ba4-4f89-8b15-7b99ef53c093-S0/frameworks/540f518e-1ba4-4f89-8b15-7b99ef53c093-0000/executors/981ca865-a5f9-42c6-8090-eaf909f78186/runs/8544eb55-baa8-495a-98e7-565ec58da673'
I1124 14:31:32.463389 30296 containerizer.cpp:617] Starting container '8544eb55-baa8-495a-98e7-565ec58da673' for executor '981ca865-a5f9-42c6-8090-eaf909f78186' of framework '540f518e-1ba4-4f89-8b15-7b99ef53c093-0000'
I1124 14:31:32.463459 30305 slave.cpp:1629] Queuing task '981ca865-a5f9-42c6-8090-eaf909f78186' for executor '981ca865-a5f9-42c6-8090-eaf909f78186' of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.463846 30305 slave.cpp:680] Successfully attached file '/tmp/ReservationEndpointsTest_UnreserveAvailableAndOfferedResources_N4vdsa/slaves/540f518e-1ba4-4f89-8b15-7b99ef53c093-S0/frameworks/540f518e-1ba4-4f89-8b15-7b99ef53c093-0000/executors/981ca865-a5f9-42c6-8090-eaf909f78186/runs/8544eb55-baa8-495a-98e7-565ec58da673'
I1124 14:31:32.468849 30301 launcher.cpp:132] Forked child with pid '3901' for container '8544eb55-baa8-495a-98e7-565ec58da673'
WARNING: Logging before InitGoogleLogging() is written to STDERR
I1124 14:31:32.614969  3915 process.cpp:936] libprocess is initialized on 172.17.6.149:55307 for 16 cpus
I1124 14:31:32.615892  3915 logging.cpp:175] Logging to STDERR
I1124 14:31:32.617889  3915 exec.cpp:134] Version: 0.27.0
I1124 14:31:32.627719  3936 exec.cpp:184] Executor started at: executor(1)@172.17.6.149:55307 with pid 3915
I1124 14:31:32.630262 30298 slave.cpp:2406] Got registration for executor '981ca865-a5f9-42c6-8090-eaf909f78186' of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 from executor(1)@172.17.6.149:55307
I1124 14:31:32.632133 30293 slave.cpp:1794] Sending queued task '981ca865-a5f9-42c6-8090-eaf909f78186' to executor '981ca865-a5f9-42c6-8090-eaf909f78186' of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 at executor(1)@172.17.6.149:55307
I1124 14:31:32.632527  3933 exec.cpp:208] Executor registered on slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0
Registered executor on c264cb162c79
I1124 14:31:32.634414  3933 exec.cpp:220] Executor::registered took 256013ns
I1124 14:31:32.634769  3933 exec.cpp:295] Executor asked to run task '981ca865-a5f9-42c6-8090-eaf909f78186'
I1124 14:31:32.634874  3933 exec.cpp:304] Executor::launchTask took 75212ns
Starting task 981ca865-a5f9-42c6-8090-eaf909f78186
Forked command at 3946
sh -c 'sleep 1000'
I1124 14:31:32.638731  3939 exec.cpp:517] Executor sending status update TASK_RUNNING (UUID: 574d2d42-c323-4733-9982-f4398c654776) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.639981 30298 slave.cpp:2763] Handling status update TASK_RUNNING (UUID: 574d2d42-c323-4733-9982-f4398c654776) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 from executor(1)@172.17.6.149:55307
I1124 14:31:32.640444 30296 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: 574d2d42-c323-4733-9982-f4398c654776) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.640498 30296 status_update_manager.cpp:497] Creating StatusUpdate stream for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.640938 30296 status_update_manager.cpp:374] Forwarding update TASK_RUNNING (UUID: 574d2d42-c323-4733-9982-f4398c654776) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 to the slave
I1124 14:31:32.641361 30301 slave.cpp:3115] Forwarding the update TASK_RUNNING (UUID: 574d2d42-c323-4733-9982-f4398c654776) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 to master@172.17.6.149:52680
I1124 14:31:32.641582 30301 slave.cpp:3009] Status update manager successfully handled status update TASK_RUNNING (UUID: 574d2d42-c323-4733-9982-f4398c654776) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.641636 30301 slave.cpp:3025] Sending acknowledgement for status update TASK_RUNNING (UUID: 574d2d42-c323-4733-9982-f4398c654776) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 to executor(1)@172.17.6.149:55307
I1124 14:31:32.641923 30306 master.cpp:4433] Status update TASK_RUNNING (UUID: 574d2d42-c323-4733-9982-f4398c654776) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 from slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 at slave(219)@172.17.6.149:52680 (c264cb162c79)
I1124 14:31:32.642014 30306 master.cpp:4481] Forwarding status update TASK_RUNNING (UUID: 574d2d42-c323-4733-9982-f4398c654776) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.642205 30306 master.cpp:6085] Updating the state of task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I1124 14:31:32.642366 30298 sched.cpp:919] Scheduler::statusUpdate took 38074ns
I1124 14:31:32.642711 30307 master.cpp:3590] Processing ACKNOWLEDGE call 574d2d42-c323-4733-9982-f4398c654776 for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 (default) at scheduler-0ff32e9c-a0bb-4f1c-a2e6-580485a123be@172.17.6.149:52680 on slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0
I1124 14:31:32.642789  3932 exec.cpp:341] Executor received status update acknowledgement 574d2d42-c323-4733-9982-f4398c654776 for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.643095 30307 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 574d2d42-c323-4733-9982-f4398c654776) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.643564 30304 slave.cpp:2346] Status update manager successfully handled status update acknowledgement (UUID: 574d2d42-c323-4733-9982-f4398c654776) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.644278 30308 master.cpp:3395] Processing REVIVE call for framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 (default) at scheduler-0ff32e9c-a0bb-4f1c-a2e6-580485a123be@172.17.6.149:52680
I1124 14:31:32.644439 30308 hierarchical.cpp:886] Removed offer filters for framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.645293 30308 hierarchical.cpp:1159] No inverse offers to send out!
I1124 14:31:32.645335 30308 hierarchical.cpp:961] Performed allocation for 1 slaves in 872704ns
I1124 14:31:32.645678 30306 master.cpp:4998] Sending 1 offers to framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 (default) at scheduler-0ff32e9c-a0bb-4f1c-a2e6-580485a123be@172.17.6.149:52680
I1124 14:31:32.646204 30297 sched.cpp:811] Scheduler::resourceOffers took 109082ns
I1124 14:31:32.646776 30299 master.cpp:3498] Telling slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 at slave(219)@172.17.6.149:52680 (c264cb162c79) to kill task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 (default) at scheduler-0ff32e9c-a0bb-4f1c-a2e6-580485a123be@172.17.6.149:52680
I1124 14:31:32.646927 30294 slave.cpp:1822] Asked to kill task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.647976  3937 exec.cpp:315] Executor asked to kill task '981ca865-a5f9-42c6-8090-eaf909f78186'
I1124 14:31:32.648072  3937 exec.cpp:324] Executor::killTask took 61578ns
Shutting down
Sending SIGTERM to process tree at pid 3946
Killing the following process trees:
[ 
-+- 3946 sh -c sleep 1000 
 \--- 3947 sleep 1000 
]
Command terminated with signal Terminated (pid: 3946)
I1124 14:31:32.738593  3939 exec.cpp:517] Executor sending status update TASK_KILLED (UUID: 26f9ee98-2124-44d0-93f0-4537c828a375) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.739966 30306 slave.cpp:2763] Handling status update TASK_KILLED (UUID: 26f9ee98-2124-44d0-93f0-4537c828a375) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 from executor(1)@172.17.6.149:55307
I1124 14:31:32.740249 30306 slave.cpp:5342] Terminating task 981ca865-a5f9-42c6-8090-eaf909f78186
I1124 14:31:32.741641 30299 status_update_manager.cpp:320] Received status update TASK_KILLED (UUID: 26f9ee98-2124-44d0-93f0-4537c828a375) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.741881 30299 status_update_manager.cpp:374] Forwarding update TASK_KILLED (UUID: 26f9ee98-2124-44d0-93f0-4537c828a375) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 to the slave
I1124 14:31:32.742216 30297 slave.cpp:3115] Forwarding the update TASK_KILLED (UUID: 26f9ee98-2124-44d0-93f0-4537c828a375) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 to master@172.17.6.149:52680
I1124 14:31:32.742477 30297 slave.cpp:3009] Status update manager successfully handled status update TASK_KILLED (UUID: 26f9ee98-2124-44d0-93f0-4537c828a375) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.742528 30297 slave.cpp:3025] Sending acknowledgement for status update TASK_KILLED (UUID: 26f9ee98-2124-44d0-93f0-4537c828a375) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 to executor(1)@172.17.6.149:55307
I1124 14:31:32.742624 30299 master.cpp:4433] Status update TASK_KILLED (UUID: 26f9ee98-2124-44d0-93f0-4537c828a375) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 from slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 at slave(219)@172.17.6.149:52680 (c264cb162c79)
I1124 14:31:32.742676 30299 master.cpp:4481] Forwarding status update TASK_KILLED (UUID: 26f9ee98-2124-44d0-93f0-4537c828a375) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.742945 30299 master.cpp:6085] Updating the state of task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
I1124 14:31:32.743191 30297 sched.cpp:919] Scheduler::statusUpdate took 26231ns
I1124 14:31:32.743536 30297 hierarchical.cpp:793] Recovered cpus(role, test-principal):1; mem(role, test-principal):128 (total: cpus(*):1; mem(*):512; disk(*):1024; ports(*):[31000-32000]; cpus(role, test-principal):1; mem(role, test-principal):512, allocated: mem(role, test-principal):384; cpus(*):1; mem(*):512; disk(*):1024; ports(*):[31000-32000]) on slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 from framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.743746 30299 master.cpp:3590] Processing ACKNOWLEDGE call 26f9ee98-2124-44d0-93f0-4537c828a375 for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 (default) at scheduler-0ff32e9c-a0bb-4f1c-a2e6-580485a123be@172.17.6.149:52680 on slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0
I1124 14:31:32.743865 30299 master.cpp:6151] Removing task 981ca865-a5f9-42c6-8090-eaf909f78186 with resources cpus(role, test-principal):1; mem(role, test-principal):128 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 on slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 at slave(219)@172.17.6.149:52680 (c264cb162c79)
I1124 14:31:32.744144  3932 exec.cpp:341] Executor received status update acknowledgement 26f9ee98-2124-44d0-93f0-4537c828a375 for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.744676 30299 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 26f9ee98-2124-44d0-93f0-4537c828a375) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.745034 30299 status_update_manager.cpp:528] Cleaning up status update stream for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.745612 30299 slave.cpp:2346] Status update manager successfully handled status update acknowledgement (UUID: 26f9ee98-2124-44d0-93f0-4537c828a375) for task 981ca865-a5f9-42c6-8090-eaf909f78186 of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.745776 30299 slave.cpp:5383] Completing task 981ca865-a5f9-42c6-8090-eaf909f78186
I1124 14:31:32.746186 30295 process.cpp:3067] Handling HTTP event for process 'master' with path: '/master/unreserve'
I1124 14:31:32.746253 30295 http.cpp:336] HTTP POST for /master/unreserve from 172.17.6.149:46936
I1124 14:31:32.747879 30307 hierarchical.cpp:793] Recovered cpus(*):1; mem(*):512; disk(*):1024; ports(*):[31000-32000]; mem(role, test-principal):384 (total: cpus(*):1; mem(*):512; disk(*):1024; ports(*):[31000-32000]; cpus(role, test-principal):1; mem(role, test-principal):512, allocated: ) on slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 from framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.748006 30307 hierarchical.cpp:830] Framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 filtered slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 for 5secs
I1124 14:31:32.748070 30299 sched.cpp:837] Rescinded offer 540f518e-1ba4-4f89-8b15-7b99ef53c093-O1
I1124 14:31:32.748138 30299 sched.cpp:848] Scheduler::offerRescinded took 21855ns
I1124 14:31:32.749619 30305 master.cpp:6224] Sending checkpointed resources  to slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 at slave(219)@172.17.6.149:52680 (c264cb162c79)
I1124 14:31:32.750159 30305 slave.cpp:2275] Updated checkpointed resources from cpus(role, test-principal):1; mem(role, test-principal):512 to 
I1124 14:31:32.754276 30296 master.cpp:3395] Processing REVIVE call for framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 (default) at scheduler-0ff32e9c-a0bb-4f1c-a2e6-580485a123be@172.17.6.149:52680
I1124 14:31:32.754508 30305 hierarchical.cpp:886] Removed offer filters for framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.755517 30305 hierarchical.cpp:1159] No inverse offers to send out!
I1124 14:31:32.755565 30305 hierarchical.cpp:961] Performed allocation for 1 slaves in 1.0104ms
I1124 14:31:32.755949 30298 master.cpp:4998] Sending 1 offers to framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 (default) at scheduler-0ff32e9c-a0bb-4f1c-a2e6-580485a123be@172.17.6.149:52680
I1124 14:31:32.756631 30298 sched.cpp:811] Scheduler::resourceOffers took 128650ns
I1124 14:31:32.757311 30274 sched.cpp:1803] Asked to stop the driver
I1124 14:31:32.757488 30303 sched.cpp:1041] Stopping framework '540f518e-1ba4-4f89-8b15-7b99ef53c093-0000'
I1124 14:31:32.757752 30295 master.cpp:5566] Processing TEARDOWN call for framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 (default) at scheduler-0ff32e9c-a0bb-4f1c-a2e6-580485a123be@172.17.6.149:52680
I1124 14:31:32.757786 30295 master.cpp:5578] Removing framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 (default) at scheduler-0ff32e9c-a0bb-4f1c-a2e6-580485a123be@172.17.6.149:52680
I1124 14:31:32.758023 30294 hierarchical.cpp:303] Deactivated framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.758117 30296 slave.cpp:2010] Asked to shut down framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 by master@172.17.6.149:52680
I1124 14:31:32.758167 30296 slave.cpp:2035] Shutting down framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.758249 30296 slave.cpp:3891] Shutting down executor '981ca865-a5f9-42c6-8090-eaf909f78186' of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 at executor(1)@172.17.6.149:55307
I1124 14:31:32.758635 30302 hierarchical.cpp:793] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: ) on slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0 from framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.758935 30302 hierarchical.cpp:260] Removed framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.759083 30304 master.cpp:926] Master terminating
I1124 14:31:32.759553 30303 hierarchical.cpp:410] Removed slave 540f518e-1ba4-4f89-8b15-7b99ef53c093-S0
I1124 14:31:32.759668  3938 exec.cpp:381] Executor asked to shutdown
I1124 14:31:32.759775  3938 exec.cpp:396] Executor::shutdown took 14378ns
I1124 14:31:32.759929  3938 exec.cpp:80] Scheduling shutdown of the executor
I1124 14:31:32.760166 30304 slave.cpp:3243] master@172.17.6.149:52680 exited
W1124 14:31:32.760193 30304 slave.cpp:3246] Master disconnected! Waiting for a new master to be elected
I1124 14:31:32.764683 30297 containerizer.cpp:1073] Destroying container '8544eb55-baa8-495a-98e7-565ec58da673'
I1124 14:31:32.774528 30299 containerizer.cpp:1256] Executor for container '8544eb55-baa8-495a-98e7-565ec58da673' has exited
I1124 14:31:32.776396 30296 slave.cpp:3581] Executor '981ca865-a5f9-42c6-8090-eaf909f78186' of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 terminated with signal Killed
I1124 14:31:32.776568 30296 slave.cpp:3685] Cleaning up executor '981ca865-a5f9-42c6-8090-eaf909f78186' of framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000 at executor(1)@172.17.6.149:55307
I1124 14:31:32.776974 30298 gc.cpp:54] Scheduling '/tmp/ReservationEndpointsTest_UnreserveAvailableAndOfferedResources_N4vdsa/slaves/540f518e-1ba4-4f89-8b15-7b99ef53c093-S0/frameworks/540f518e-1ba4-4f89-8b15-7b99ef53c093-0000/executors/981ca865-a5f9-42c6-8090-eaf909f78186/runs/8544eb55-baa8-495a-98e7-565ec58da673' for gc 6.99999100884444days in the future
I1124 14:31:32.777122 30296 slave.cpp:3773] Cleaning up framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.777163 30298 gc.cpp:54] Scheduling '/tmp/ReservationEndpointsTest_UnreserveAvailableAndOfferedResources_N4vdsa/slaves/540f518e-1ba4-4f89-8b15-7b99ef53c093-S0/frameworks/540f518e-1ba4-4f89-8b15-7b99ef53c093-0000/executors/981ca865-a5f9-42c6-8090-eaf909f78186' for gc 6.99999100695704days in the future
I1124 14:31:32.777220 30301 status_update_manager.cpp:282] Closing status update streams for framework 540f518e-1ba4-4f89-8b15-7b99ef53c093-0000
I1124 14:31:32.777307 30296 slave.cpp:599] Slave terminating
I1124 14:31:32.777298 30298 gc.cpp:54] Scheduling '/tmp/ReservationEndpointsTest_UnreserveAvailableAndOfferedResources_N4vdsa/slaves/540f518e-1ba4-4f89-8b15-7b99ef53c093-S0/frameworks/540f518e-1ba4-4f89-8b15-7b99ef53c093-0000' for gc 6.99999100426074days in the future
[       OK ] ReservationEndpointsTest.UnreserveAvailableAndOfferedResources (409 ms)

Attachments

Activity

People

Assignee:: Anand Mazumdar

Reporter:: Anand Mazumdar

Shepherd:: Michael Park

Votes:: 0 Vote for this issue

Watchers:: 3 Start watching this issue

Dates

Created:: 24/Nov/15 19:57

Updated:: 03/Mar/16 17:05

Resolved:: 03/Dec/15 08:54