[MESOS-4940] MemoryPressureMesosTest.CGROUPS_ROOT_Statistics is flaky - ASF JIRA

XML

Word

Printable

JSON

Details

Type: Bug
Status: Resolved
Priority: Major
Resolution: Won't Fix
Affects Version/s: None
Fix Version/s: None
Component/s: test
Labels:
- flaky-test
- mesosphere
Environment:

CentOS 7 and Ubuntu 14.04, using gcc, with libevent and SSL enabled

Epic Link:
flaky

Description

Verbose log from a failed run:

Repeating all tests (iteration 79) . . .

Note: Google Test filter = MemoryPressureMesosTest.CGROUPS_ROOT_Statistics-HierarchicalAllocator_BENCHMARK_Test.DeclineOffers:HierarchicalAllocator_BENCHMARK_Test.ResourceLabels:MesosContainerizerSlaveRecoveryTest.CGROUPS_ROOT_PerfRollForward:NetClsIsolatorTest.ROOT_CGROUPS_NetClsIsolate:NetClsIsolatorTest.ROOT_CGROUPS_ContainerStatus:PerfEventIsolatorTest.ROOT_CGROUPS_Sample:UserCgroupIsolatorTest/0.ROOT_CGROUPS_UserCgroup:UserCgroupIsolatorTest/1.ROOT_CGROUPS_UserCgroup:UserCgroupIsolatorTest/2.ROOT_CGROUPS_UserCgroup:OverlayBackendTest.ROOT_OVERLAYFS_OverlayFSBackend:CgroupsNoHierarchyTest.ROOT_CGROUPS_NOHIERARCHY_MountUnmountHierarchy:CgroupsAnyHierarchyWithPerfEventTest.ROOT_CGROUPS_Perf:PerfTest.ROOT_Events:PerfTest.ROOT_Sample:PerfTest.Parse:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/0:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/1:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/2:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/3:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/4:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/5:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/6:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/7:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/8:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/9:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/10:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/11:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/12:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/13:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/14:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/15:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/16:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/17:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/18:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/19:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/20:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/21:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/22:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/23:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/24:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/25:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/26:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/27:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/28:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/29:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/30:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/31:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/32:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/33:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/34:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/35:SlaveCount/Registrar_BENCHMARK_Test.Performance/0:SlaveCount/Registrar_BENCHMARK_Test.Performance/1:SlaveCount/Registrar_BENCHMARK_Test.Performance/2:SlaveCount/Registrar_BENCHMARK_Test.Performance/3
[==========] Running 1 test from 1 test case.
[----------] Global test environment set-up.
[----------] 1 test from MemoryPressureMesosTest
1+0 records in
1+0 records out
1048576 bytes (1.0 MB) copied, 0.000598611 s, 1.8 GB/s
[ RUN      ] MemoryPressureMesosTest.CGROUPS_ROOT_Statistics
I0314 19:33:46.741968 49933 process.cpp:2484] Spawned process files@172.31.14.224:50909
I0314 19:33:46.742004 49953 process.cpp:2494] Resuming files@172.31.14.224:50909 at 2016-03-14 19:33:46.741981952+00:00
I0314 19:33:46.742221 49951 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.742201088+00:00
I0314 19:33:46.767947 49947 process.cpp:2494] Resuming reaper(1)@172.31.14.224:50909 at 2016-03-14 19:33:46.767932928+00:00
I0314 19:33:46.783123 49933 process.cpp:2484] Spawned process (5455)@172.31.14.224:50909
I0314 19:33:46.783125 49955 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:46.783107072+00:00
I0314 19:33:46.783136 49958 process.cpp:2494] Resuming (5455)@172.31.14.224:50909 at 2016-03-14 19:33:46.783117056+00:00
I0314 19:33:46.790949 49933 leveldb.cpp:174] Opened db in 7.717349ms
I0314 19:33:46.793222 49933 leveldb.cpp:181] Compacted db in 2.233394ms
I0314 19:33:46.793277 49933 leveldb.cpp:196] Created db iterator in 17424ns
I0314 19:33:46.793298 49933 leveldb.cpp:202] Seeked to beginning of db in 1874ns
I0314 19:33:46.793310 49933 leveldb.cpp:271] Iterated through 0 keys in the db in 373ns
I0314 19:33:46.793350 49933 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0314 19:33:46.793465 49933 process.cpp:2484] Spawned process log-replica(79)@172.31.14.224:50909
I0314 19:33:46.793505 49948 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.793480960+00:00
I0314 19:33:46.793623 49933 process.cpp:2484] Spawned process (5456)@172.31.14.224:50909
I0314 19:33:46.793648 49952 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.793628928+00:00
I0314 19:33:46.793695 49953 process.cpp:2494] Resuming log(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.793686016+00:00
I0314 19:33:46.793745 49933 process.cpp:2484] Spawned process log(79)@172.31.14.224:50909
I0314 19:33:46.793845 49933 process.cpp:2484] Spawned process log-reader(79)@172.31.14.224:50909
I0314 19:33:46.793862 49950 process.cpp:2494] Resuming log-reader(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.793846016+00:00
I0314 19:33:46.793843 49962 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.793827072+00:00
I0314 19:33:46.793937 49955 process.cpp:2494] Resuming log-writer(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.793926912+00:00
I0314 19:33:46.793962 49933 process.cpp:2484] Spawned process log-writer(79)@172.31.14.224:50909
I0314 19:33:46.794037 49953 process.cpp:2484] Spawned process log-recover(79)@172.31.14.224:50909
I0314 19:33:46.794040 49958 process.cpp:2494] Resuming log-recover(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.794032128+00:00
I0314 19:33:46.794080 49949 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:46.794059008+00:00
I0314 19:33:46.794107 49958 recover.cpp:447] Starting replica recovery
I0314 19:33:46.794196 49953 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.794189056+00:00
I0314 19:33:46.794222 49933 process.cpp:2484] Spawned process (5457)@172.31.14.224:50909
I0314 19:33:46.794231 49959 process.cpp:2494] Resuming (5457)@172.31.14.224:50909 at 2016-03-14 19:33:46.794210048+00:00
I0314 19:33:46.794332 49955 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:46.794324992+00:00
I0314 19:33:46.794343 49956 process.cpp:2494] Resuming log-recover(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.794319872+00:00
I0314 19:33:46.794395 49956 recover.cpp:473] Replica is in EMPTY status
I0314 19:33:46.794543 49956 process.cpp:2484] Spawned process log-recover-protocol(157)@172.31.14.224:50909
I0314 19:33:46.794559 49953 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.794551040+00:00
I0314 19:33:46.794558 49933 process.cpp:2484] Spawned process registrar(79)@172.31.14.224:50909
I0314 19:33:46.794582 49948 process.cpp:2494] Resuming registrar(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.794573056+00:00
I0314 19:33:46.794582 49957 process.cpp:2494] Resuming log-recover-protocol(157)@172.31.14.224:50909 at 2016-03-14 19:33:46.794564096+00:00
I0314 19:33:46.794661 49956 process.cpp:2494] Resuming standalone-master-detector(235)@172.31.14.224:50909 at 2016-03-14 19:33:46.794652928+00:00
I0314 19:33:46.794670 49933 process.cpp:2484] Spawned process standalone-master-detector(235)@172.31.14.224:50909
I0314 19:33:46.794685 49957 recover.cpp:129] Starting to wait for enough quorum of replicas before running recovery protocol, expected quroum size: 1
I0314 19:33:46.794795 49960 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.794774016+00:00
I0314 19:33:46.794821 49949 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.794810880+00:00
I0314 19:33:46.794834 49961 process.cpp:2494] Resuming authorizer(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.794804992+00:00
I0314 19:33:46.794805 49933 process.cpp:2484] Spawned process authorizer(79)@172.31.14.224:50909
I0314 19:33:46.794992 49957 process.cpp:2484] Spawned process __latch__(1948)@172.31.14.224:50909
I0314 19:33:46.795018 49958 process.cpp:2494] Resuming __latch__(1948)@172.31.14.224:50909 at 2016-03-14 19:33:46.795009024+00:00
I0314 19:33:46.795008 49960 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.794999040+00:00
I0314 19:33:46.795151 49957 recover.cpp:143] Broadcasting recover request to all replicas
I0314 19:33:46.795234 49955 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:46.795225088+00:00
I0314 19:33:46.795244 49951 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.795234048+00:00
I0314 19:33:46.795383 49949 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.795374080+00:00
I0314 19:33:46.795385 49951 process.cpp:2484] Spawned process (5458)@172.31.14.224:50909
I0314 19:33:46.795397 49959 process.cpp:2494] Resuming (5458)@172.31.14.224:50909 at 2016-03-14 19:33:46.795388928+00:00
I0314 19:33:46.795459 49949 process.cpp:2494] Resuming (5458)@172.31.14.224:50909 at 2016-03-14 19:33:46.795451904+00:00
I0314 19:33:46.795636 49962 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.795623936+00:00
I0314 19:33:46.795662 49956 process.cpp:2494] Resuming log-recover-protocol(157)@172.31.14.224:50909 at 2016-03-14 19:33:46.795652096+00:00
I0314 19:33:46.795706 49956 recover.cpp:152] Broadcast request completed
I0314 19:33:46.795702 49962 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (5458)@172.31.14.224:50909
I0314 19:33:46.795804 49962 process.cpp:2494] Resuming (5458)@172.31.14.224:50909 at 2016-03-14 19:33:46.795796992+00:00
I0314 19:33:46.795891 49962 process.cpp:2599] Cleaning up (5458)@172.31.14.224:50909
I0314 19:33:46.795991 49947 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.795979008+00:00
I0314 19:33:46.796012 49958 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.796005120+00:00
I0314 19:33:46.796212 49956 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0314 19:33:46.796216 49951 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:46.796206080+00:00
I0314 19:33:46.796394 49953 process.cpp:2494] Resuming __latch__(1948)@172.31.14.224:50909 at 2016-03-14 19:33:46.796386048+00:00
I0314 19:33:46.796409 49950 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:46.796401920+00:00
I0314 19:33:46.796438 49953 process.cpp:2599] Cleaning up __latch__(1948)@172.31.14.224:50909
I0314 19:33:46.796568 49962 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.796558080+00:00
I0314 19:33:46.796592 49947 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.796582912+00:00
I0314 19:33:46.796638 49961 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:46.796630016+00:00
I0314 19:33:46.796650 49947 process.cpp:2494] Resuming log-recover(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.796643072+00:00
I0314 19:33:46.796686 49956 process.cpp:2599] Cleaning up log-recover-protocol(157)@172.31.14.224:50909
I0314 19:33:46.796694 49947 recover.cpp:564] Updating replica status to STARTING
I0314 19:33:46.796778 49960 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.796768000+00:00
I0314 19:33:46.796803 49959 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.796794880+00:00
I0314 19:33:46.796783 49957 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:46.796771072+00:00
I0314 19:33:46.796782 49951 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.796774912+00:00
I0314 19:33:46.797379 49958 process.cpp:2494] Resuming standalone-master-detector(235)@172.31.14.224:50909 at 2016-03-14 19:33:46.797370880+00:00
I0314 19:33:46.797538 49933 process.cpp:2484] Spawned process master@172.31.14.224:50909
I0314 19:33:46.797562 49949 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:46.797550080+00:00
I0314 19:33:46.797601 49949 master.cpp:375] Master dbfcd71c-47c4-4b7a-bdff-6335751ecebe (ip-172-31-14-224.us-west-1.compute.internal) started on 172.31.14.224:50909
I0314 19:33:46.797639 49958 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.797628928+00:00
I0314 19:33:46.797686 49933 process.cpp:2484] Spawned process __latch__(1949)@172.31.14.224:50909
I0314 19:33:46.797713 49954 process.cpp:2494] Resuming __latch__(1949)@172.31.14.224:50909 at 2016-03-14 19:33:46.797689088+00:00
I0314 19:33:46.797616 49949 master.cpp:377] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="true" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/beHcrQ/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="100secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/beHcrQ/master" --zk_session_timeout="10secs"
I0314 19:33:46.797821 49933 process.cpp:2484] Spawned process __waiter__(805)@172.31.14.224:50909
I0314 19:33:46.797858 49949 master.cpp:422] Master only allowing authenticated frameworks to register
I0314 19:33:46.797884 49949 master.cpp:427] Master only allowing authenticated slaves to register
I0314 19:33:46.797917 49949 credentials.hpp:35] Loading credentials for authentication from '/tmp/beHcrQ/credentials'
I0314 19:33:46.797855 49950 process.cpp:2494] Resuming __waiter__(805)@172.31.14.224:50909 at 2016-03-14 19:33:46.797844992+00:00
I0314 19:33:46.798856 49949 master.cpp:467] Using default 'crammd5' authenticator
I0314 19:33:46.798976 49949 process.cpp:2484] Spawned process crammd5_authenticator(79)@172.31.14.224:50909
I0314 19:33:46.798996 49960 process.cpp:2494] Resuming crammd5_authenticator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.798988032+00:00
I0314 19:33:46.799012 49949 master.cpp:536] Using default 'basic' HTTP authenticator
I0314 19:33:46.799118 49949 process.cpp:2484] Spawned process (5459)@172.31.14.224:50909
I0314 19:33:46.799118 49948 process.cpp:2494] Resuming (5459)@172.31.14.224:50909 at 2016-03-14 19:33:46.799106048+00:00
I0314 19:33:46.799211 49957 process.cpp:2494] Resuming AuthenticationRouter(1)@172.31.14.224:50909 at 2016-03-14 19:33:46.799203072+00:00
I0314 19:33:46.799222 49949 master.cpp:570] Authorization enabled
I0314 19:33:46.799309 49951 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 2.409353ms
I0314 19:33:46.799348 49951 replica.cpp:320] Persisted replica status to STARTING
I0314 19:33:46.799346 49958 process.cpp:2494] Resuming (5455)@172.31.14.224:50909 at 2016-03-14 19:33:46.799339008+00:00
I0314 19:33:46.799442 49958 hierarchical.cpp:144] Initialized hierarchical allocator process
I0314 19:33:46.799449 49948 process.cpp:2494] Resuming log-recover(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.799440896+00:00
I0314 19:33:46.799444 49962 process.cpp:2494] Resuming whitelist(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.799436032+00:00
I0314 19:33:46.799495 49949 process.cpp:2484] Spawned process whitelist(79)@172.31.14.224:50909
I0314 19:33:46.799526 49962 whitelist_watcher.cpp:77] No whitelist given
I0314 19:33:46.799607 49948 recover.cpp:473] Replica is in STARTING status
I0314 19:33:46.799737 49948 process.cpp:2484] Spawned process log-recover-protocol(158)@172.31.14.224:50909
I0314 19:33:46.799763 49958 process.cpp:2494] Resuming log-recover-protocol(158)@172.31.14.224:50909 at 2016-03-14 19:33:46.799755008+00:00
I0314 19:33:46.799748 49957 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.799739904+00:00
I0314 19:33:46.799823 49958 recover.cpp:129] Starting to wait for enough quorum of replicas before running recovery protocol, expected quroum size: 1
I0314 19:33:46.799932 49959 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.799922944+00:00
I0314 19:33:46.800025 49961 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.800016896+00:00
I0314 19:33:46.800045 49958 process.cpp:2484] Spawned process __latch__(1950)@172.31.14.224:50909
I0314 19:33:46.800066 49956 process.cpp:2494] Resuming __latch__(1950)@172.31.14.224:50909 at 2016-03-14 19:33:46.800055040+00:00
I0314 19:33:46.800092 49951 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.800083968+00:00
I0314 19:33:46.800206 49958 recover.cpp:143] Broadcasting recover request to all replicas
I0314 19:33:46.800305 49957 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.800296960+00:00
I0314 19:33:46.800436 49957 process.cpp:2484] Spawned process (5460)@172.31.14.224:50909
I0314 19:33:46.800453 49956 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.800444928+00:00
I0314 19:33:46.800474 49960 process.cpp:2494] Resuming (5460)@172.31.14.224:50909 at 2016-03-14 19:33:46.800464896+00:00
I0314 19:33:46.800570 49959 process.cpp:2494] Resuming log-recover-protocol(158)@172.31.14.224:50909 at 2016-03-14 19:33:46.800558080+00:00
I0314 19:33:46.800626 49954 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.800614912+00:00
I0314 19:33:46.800663 49959 recover.cpp:152] Broadcast request completed
I0314 19:33:46.800690 49954 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (5460)@172.31.14.224:50909
I0314 19:33:46.800772 49954 process.cpp:2494] Resuming (5460)@172.31.14.224:50909 at 2016-03-14 19:33:46.800765952+00:00
I0314 19:33:46.800923 49954 process.cpp:2599] Cleaning up (5460)@172.31.14.224:50909
I0314 19:33:46.800974 49959 recover.cpp:193] Received a recover response from a replica in STARTING status
I0314 19:33:46.801028 49957 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.801018880+00:00
I0314 19:33:46.801084 49962 process.cpp:2494] Resuming __latch__(1950)@172.31.14.224:50909 at 2016-03-14 19:33:46.801078016+00:00
I0314 19:33:46.801111 49947 process.cpp:2494] Resuming standalone-master-detector(235)@172.31.14.224:50909 at 2016-03-14 19:33:46.801100032+00:00
I0314 19:33:46.801197 49962 process.cpp:2599] Cleaning up __latch__(1950)@172.31.14.224:50909
I0314 19:33:46.801306 49954 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.801297920+00:00
I0314 19:33:46.801363 49962 process.cpp:2494] Resuming log-recover(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.801351936+00:00
I0314 19:33:46.801390 49956 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:46.801379072+00:00
I0314 19:33:46.801401 49959 process.cpp:2599] Cleaning up log-recover-protocol(158)@172.31.14.224:50909
I0314 19:33:46.801431 49962 recover.cpp:564] Updating replica status to VOTING
I0314 19:33:46.801478 49956 master.cpp:1711] The newly elected leader is master@172.31.14.224:50909 with id dbfcd71c-47c4-4b7a-bdff-6335751ecebe
I0314 19:33:46.801522 49956 master.cpp:1724] Elected as the leading master!
I0314 19:33:46.801556 49949 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.801543936+00:00
I0314 19:33:46.801563 49956 master.cpp:1469] Recovering from registrar
I0314 19:33:46.801633 49948 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.801622016+00:00
I0314 19:33:46.801712 49947 process.cpp:2494] Resuming registrar(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.801702912+00:00
I0314 19:33:46.801874 49947 registrar.cpp:307] Recovering registrar
I0314 19:33:46.801942 49957 process.cpp:2494] Resuming standalone-master-detector(235)@172.31.14.224:50909 at 2016-03-14 19:33:46.801934080+00:00
I0314 19:33:46.801995 49960 process.cpp:2494] Resuming (5457)@172.31.14.224:50909 at 2016-03-14 19:33:46.801985024+00:00
I0314 19:33:46.802119 49960 log.cpp:240] Starting the writer
I0314 19:33:46.802129 49947 process.cpp:2484] Spawned process __latch__(1951)@172.31.14.224:50909
I0314 19:33:46.802124 49957 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.802115072+00:00
I0314 19:33:46.802152 49958 process.cpp:2494] Resuming __latch__(1951)@172.31.14.224:50909 at 2016-03-14 19:33:46.802139904+00:00
I0314 19:33:46.802229 49951 process.cpp:2494] Resuming log-writer(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.802220032+00:00
I0314 19:33:46.803527 49948 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 1.817447ms
I0314 19:33:46.803561 49948 replica.cpp:320] Persisted replica status to VOTING
I0314 19:33:46.803648 49953 process.cpp:2494] Resuming log-recover(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.803636992+00:00
I0314 19:33:46.803702 49953 recover.cpp:578] Successfully joined the Paxos group
I0314 19:33:46.803819 49947 process.cpp:2494] Resuming log(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.803809024+00:00
I0314 19:33:46.803848 49953 recover.cpp:462] Recover process terminated
I0314 19:33:46.803870 49953 process.cpp:2599] Cleaning up log-recover(79)@172.31.14.224:50909
I0314 19:33:46.803871 49947 log.cpp:356] Log recovery completed
I0314 19:33:46.803932 49950 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.803921920+00:00
I0314 19:33:46.803977 49951 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.803969024+00:00
I0314 19:33:46.804056 49951 process.cpp:2494] Resuming log-reader(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.804047104+00:00
I0314 19:33:46.804168 49958 process.cpp:2494] Resuming log-writer(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.804157952+00:00
I0314 19:33:46.804373 49958 process.cpp:2484] Spawned process log-coordinator(79)@172.31.14.224:50909
I0314 19:33:46.804397 49953 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.804387072+00:00
I0314 19:33:46.804409 49958 log.cpp:659] Attempting to start the writer
I0314 19:33:46.804533 49961 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.804524032+00:00
I0314 19:33:46.804677 49951 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.804666880+00:00
I0314 19:33:46.804955 49961 process.cpp:2484] Spawned process log-implicit-promise(79)@172.31.14.224:50909
I0314 19:33:46.804973 49962 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.804963072+00:00
I0314 19:33:46.804988 49954 process.cpp:2494] Resuming log-implicit-promise(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.804978944+00:00
I0314 19:33:46.805074 49956 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.805062912+00:00
I0314 19:33:46.805179 49955 process.cpp:2494] Resuming log-implicit-promise(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.805169920+00:00
I0314 19:33:46.805327 49958 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.805317120+00:00
I0314 19:33:46.805455 49958 process.cpp:2484] Spawned process (5461)@172.31.14.224:50909
I0314 19:33:46.805474 49947 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.805465088+00:00
I0314 19:33:46.805490 49961 process.cpp:2494] Resuming (5461)@172.31.14.224:50909 at 2016-03-14 19:33:46.805480960+00:00
I0314 19:33:46.805572 49947 process.cpp:2494] Resuming log-implicit-promise(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.805562880+00:00
I0314 19:33:46.805588 49950 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.805580032+00:00
I0314 19:33:46.805677 49950 replica.cpp:493] Replica received implicit promise request from (5461)@172.31.14.224:50909 with proposal 1
I0314 19:33:46.807467 49950 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 1.743371ms
I0314 19:33:46.807502 49950 replica.cpp:342] Persisted promised to 1
I0314 19:33:46.807559 49950 process.cpp:2494] Resuming (5461)@172.31.14.224:50909 at 2016-03-14 19:33:46.807553024+00:00
I0314 19:33:46.807657 49953 process.cpp:2494] Resuming log-implicit-promise(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.807646976+00:00
I0314 19:33:46.807678 49950 process.cpp:2599] Cleaning up (5461)@172.31.14.224:50909
I0314 19:33:46.807765 49958 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.807753984+00:00
I0314 19:33:46.807798 49957 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.807789056+00:00
I0314 19:33:46.807919 49953 process.cpp:2599] Cleaning up log-implicit-promise(79)@172.31.14.224:50909
I0314 19:33:46.807925 49949 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.807916032+00:00
I0314 19:33:46.807943 49959 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.807933952+00:00
I0314 19:33:46.807994 49947 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.807984896+00:00
I0314 19:33:46.808076 49956 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.808068096+00:00
I0314 19:33:46.808137 49956 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0314 19:33:46.808269 49956 process.cpp:2484] Spawned process log-bulk-catch-up(79)@172.31.14.224:50909
I0314 19:33:46.808289 49950 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.808279040+00:00
I0314 19:33:46.808300 49959 process.cpp:2494] Resuming log-bulk-catch-up(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.808293120+00:00
I0314 19:33:46.808406 49959 process.cpp:2484] Spawned process log-catch-up(79)@172.31.14.224:50909
I0314 19:33:46.808404 49952 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.808395008+00:00
I0314 19:33:46.808418 49947 process.cpp:2494] Resuming log-catch-up(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.808410112+00:00
I0314 19:33:46.808558 49961 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.808547072+00:00
I0314 19:33:46.808648 49949 process.cpp:2494] Resuming log-catch-up(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.808640000+00:00
I0314 19:33:46.808779 49949 process.cpp:2484] Spawned process log-fill(79)@172.31.14.224:50909
I0314 19:33:46.808799 49954 process.cpp:2494] Resuming log-fill(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.808787968+00:00
I0314 19:33:46.808907 49954 process.cpp:2484] Spawned process log-explicit-promise(79)@172.31.14.224:50909
I0314 19:33:46.808923 49957 process.cpp:2494] Resuming log-explicit-promise(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.808913920+00:00
I0314 19:33:46.808959 49948 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.808946944+00:00
I0314 19:33:46.809025 49962 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.809015040+00:00
I0314 19:33:46.809128 49959 process.cpp:2494] Resuming log-explicit-promise(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.809118976+00:00
I0314 19:33:46.809243 49962 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.809235968+00:00
I0314 19:33:46.809362 49962 process.cpp:2484] Spawned process (5462)@172.31.14.224:50909
I0314 19:33:46.809381 49958 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.809370880+00:00
I0314 19:33:46.809392 49959 process.cpp:2494] Resuming (5462)@172.31.14.224:50909 at 2016-03-14 19:33:46.809384960+00:00
I0314 19:33:46.809465 49951 process.cpp:2494] Resuming log-explicit-promise(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.809455104+00:00
I0314 19:33:46.809486 49954 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.809477120+00:00
I0314 19:33:46.809558 49954 replica.cpp:388] Replica received explicit promise request from (5462)@172.31.14.224:50909 for position 0 with proposal 2
I0314 19:33:46.811501 49954 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 1.891603ms
I0314 19:33:46.811537 49954 replica.cpp:712] Persisted action at 0
I0314 19:33:46.811604 49954 process.cpp:2494] Resuming (5462)@172.31.14.224:50909 at 2016-03-14 19:33:46.811596032+00:00
I0314 19:33:46.811697 49956 process.cpp:2494] Resuming log-explicit-promise(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.811688960+00:00
I0314 19:33:46.811717 49954 process.cpp:2599] Cleaning up (5462)@172.31.14.224:50909
I0314 19:33:46.811791 49947 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.811782912+00:00
I0314 19:33:46.811810 49957 process.cpp:2494] Resuming log-fill(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.811800064+00:00
I0314 19:33:46.811846 49953 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.811834880+00:00
I0314 19:33:46.811925 49956 process.cpp:2599] Cleaning up log-explicit-promise(79)@172.31.14.224:50909
I0314 19:33:46.811947 49947 process.cpp:2494] Resuming log-write(391)@172.31.14.224:50909 at 2016-03-14 19:33:46.811940096+00:00
I0314 19:33:46.811933 49957 process.cpp:2484] Spawned process log-write(391)@172.31.14.224:50909
I0314 19:33:46.811993 49961 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.811983872+00:00
I0314 19:33:46.812175 49960 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.812165120+00:00
I0314 19:33:46.812216 49948 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.812208128+00:00
I0314 19:33:46.812314 49956 process.cpp:2494] Resuming log-write(391)@172.31.14.224:50909 at 2016-03-14 19:33:46.812305920+00:00
I0314 19:33:46.812458 49950 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.812450048+00:00
I0314 19:33:46.812583 49950 process.cpp:2484] Spawned process (5463)@172.31.14.224:50909
I0314 19:33:46.812594 49952 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.812585984+00:00
I0314 19:33:46.812598 49956 process.cpp:2494] Resuming (5463)@172.31.14.224:50909 at 2016-03-14 19:33:46.812589056+00:00
I0314 19:33:46.812738 49960 process.cpp:2494] Resuming log-write(391)@172.31.14.224:50909 at 2016-03-14 19:33:46.812730880+00:00
I0314 19:33:46.812749 49950 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.812739072+00:00
I0314 19:33:46.812810 49950 replica.cpp:537] Replica received write request for position 0 from (5463)@172.31.14.224:50909
I0314 19:33:46.812865 49950 leveldb.cpp:436] Reading position from leveldb took 21991ns
I0314 19:33:46.815364 49950 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 2.456055ms
I0314 19:33:46.815399 49950 replica.cpp:712] Persisted action at 0
I0314 19:33:46.815464 49950 process.cpp:2494] Resuming (5463)@172.31.14.224:50909 at 2016-03-14 19:33:46.815456000+00:00
I0314 19:33:46.815562 49950 process.cpp:2599] Cleaning up (5463)@172.31.14.224:50909
I0314 19:33:46.815568 49961 process.cpp:2494] Resuming log-write(391)@172.31.14.224:50909 at 2016-03-14 19:33:46.815557888+00:00
I0314 19:33:46.815634 49962 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.815623936+00:00
I0314 19:33:46.815703 49962 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.815697920+00:00
I0314 19:33:46.815850 49962 process.cpp:2494] Resuming log-fill(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.815843072+00:00
I0314 19:33:46.815991 49961 process.cpp:2599] Cleaning up log-write(391)@172.31.14.224:50909
I0314 19:33:46.816051 49959 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.816043008+00:00
I0314 19:33:46.816082 49953 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.816075008+00:00
I0314 19:33:46.816112 49958 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.816101120+00:00
I0314 19:33:46.816172 49951 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.816164096+00:00
I0314 19:33:46.816215 49958 process.cpp:2494] Resuming log-fill(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.816205056+00:00
I0314 19:33:46.816238 49951 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0314 19:33:46.816364 49962 process.cpp:2494] Resuming log-catch-up(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.816354048+00:00
I0314 19:33:46.816370 49958 process.cpp:2599] Cleaning up log-fill(79)@172.31.14.224:50909
I0314 19:33:46.816535 49950 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.816526080+00:00
I0314 19:33:46.816656 49962 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.816647936+00:00
I0314 19:33:46.818011 49951 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 1.723974ms
I0314 19:33:46.818043 49951 replica.cpp:712] Persisted action at 0
I0314 19:33:46.818063 49951 replica.cpp:697] Replica learned NOP action at position 0
I0314 19:33:46.818145 49951 process.cpp:2494] Resuming log-catch-up(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.818138880+00:00
I0314 19:33:46.818234 49959 process.cpp:2494] Resuming log-bulk-catch-up(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.818224896+00:00
I0314 19:33:46.818250 49951 process.cpp:2599] Cleaning up log-catch-up(79)@172.31.14.224:50909
I0314 19:33:46.818322 49949 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.818313984+00:00
I0314 19:33:46.818331 49957 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.818321920+00:00
I0314 19:33:46.818399 49956 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.818382080+00:00
I0314 19:33:46.818557 49959 process.cpp:2599] Cleaning up log-bulk-catch-up(79)@172.31.14.224:50909
I0314 19:33:46.818636 49952 process.cpp:2494] Resuming log-writer(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.818626048+00:00
I0314 19:33:46.818662 49947 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.818652928+00:00
I0314 19:33:46.818708 49958 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.818699008+00:00
I0314 19:33:46.818750 49952 log.cpp:675] Writer started with ending position 0
I0314 19:33:46.818836 49961 process.cpp:2494] Resuming (5457)@172.31.14.224:50909 at 2016-03-14 19:33:46.818827008+00:00
I0314 19:33:46.818889 49961 log.cpp:261] Writer got elected at position
I0314 19:33:46.818981 49960 process.cpp:2494] Resuming log-reader(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.818970880+00:00
I0314 19:33:46.819226 49947 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.819217920+00:00
I0314 19:33:46.819365 49955 process.cpp:2494] Resuming (5457)@172.31.14.224:50909 at 2016-03-14 19:33:46.819354112+00:00
I0314 19:33:46.819504 49951 process.cpp:2494] Resuming log-reader(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.819494912+00:00
I0314 19:33:46.819767 49954 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.819758080+00:00
I0314 19:33:46.819820 49954 replica.cpp:222] Starting read from '0' to '0'
I0314 19:33:46.819870 49954 leveldb.cpp:436] Reading position from leveldb took 21301ns
I0314 19:33:46.820042 49957 process.cpp:2494] Resuming log-reader(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.820033024+00:00
I0314 19:33:46.820184 49952 process.cpp:2494] Resuming (5457)@172.31.14.224:50909 at 2016-03-14 19:33:46.820175872+00:00
I0314 19:33:46.820250 49952 log.cpp:303] Applying operations (0 entries)
I0314 19:33:46.820559 49962 process.cpp:2494] Resuming __latch__(1951)@172.31.14.224:50909 at 2016-03-14 19:33:46.820550912+00:00
I0314 19:33:46.820597 49962 process.cpp:2599] Cleaning up __latch__(1951)@172.31.14.224:50909
I0314 19:33:46.820655 49955 process.cpp:2494] Resuming registrar(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.820645888+00:00
I0314 19:33:46.820669 49948 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.820657920+00:00
I0314 19:33:46.820688 49950 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.820678912+00:00
I0314 19:33:46.820722 49955 registrar.cpp:340] Successfully fetched the registry (0B) in 18.797056ms
I0314 19:33:46.820827 49955 registrar.cpp:439] Applied 1 operations in 19407ns; attempting to update the 'registry'
I0314 19:33:46.820984 49959 process.cpp:2494] Resuming (5457)@172.31.14.224:50909 at 2016-03-14 19:33:46.820976128+00:00
I0314 19:33:46.821094 49955 process.cpp:2484] Spawned process __latch__(1952)@172.31.14.224:50909
I0314 19:33:46.821108 49951 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.821099008+00:00
I0314 19:33:46.821117 49958 process.cpp:2494] Resuming __latch__(1952)@172.31.14.224:50909 at 2016-03-14 19:33:46.821106944+00:00
I0314 19:33:46.821439 49957 process.cpp:2494] Resuming log-writer(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.821430016+00:00
I0314 19:33:46.821499 49957 log.cpp:683] Attempting to append 240 bytes to the log
I0314 19:33:46.821590 49948 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.821581056+00:00
I0314 19:33:46.821648 49948 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0314 19:33:46.821753 49948 process.cpp:2484] Spawned process log-write(392)@172.31.14.224:50909
I0314 19:33:46.821771 49947 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.821761024+00:00
I0314 19:33:46.821795 49952 process.cpp:2494] Resuming log-write(392)@172.31.14.224:50909 at 2016-03-14 19:33:46.821783040+00:00
I0314 19:33:46.821895 49950 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.821885952+00:00
I0314 19:33:46.821986 49949 process.cpp:2494] Resuming log-write(392)@172.31.14.224:50909 at 2016-03-14 19:33:46.821978112+00:00
I0314 19:33:46.822100 49953 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.822092032+00:00
I0314 19:33:46.822222 49953 process.cpp:2484] Spawned process (5464)@172.31.14.224:50909
I0314 19:33:46.822239 49954 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.822230016+00:00
I0314 19:33:46.822252 49950 process.cpp:2494] Resuming (5464)@172.31.14.224:50909 at 2016-03-14 19:33:46.822243072+00:00
I0314 19:33:46.822340 49953 process.cpp:2494] Resuming log-write(392)@172.31.14.224:50909 at 2016-03-14 19:33:46.822331904+00:00
I0314 19:33:46.822355 49956 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.822343936+00:00
I0314 19:33:46.822417 49956 replica.cpp:537] Replica received write request for position 1 from (5464)@172.31.14.224:50909
I0314 19:33:46.824129 49956 leveldb.cpp:341] Persisting action (259 bytes) to leveldb took 1.674734ms
I0314 19:33:46.824164 49956 replica.cpp:712] Persisted action at 1
I0314 19:33:46.824226 49956 process.cpp:2494] Resuming (5464)@172.31.14.224:50909 at 2016-03-14 19:33:46.824219904+00:00
I0314 19:33:46.824331 49957 process.cpp:2494] Resuming log-write(392)@172.31.14.224:50909 at 2016-03-14 19:33:46.824322048+00:00
I0314 19:33:46.824334 49956 process.cpp:2599] Cleaning up (5464)@172.31.14.224:50909
I0314 19:33:46.824429 49954 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.824419072+00:00
I0314 19:33:46.824443 49952 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.824432896+00:00
I0314 19:33:46.824478 49958 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.824468992+00:00
I0314 19:33:46.824576 49957 process.cpp:2599] Cleaning up log-write(392)@172.31.14.224:50909
I0314 19:33:46.824596 49961 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.824585984+00:00
I0314 19:33:46.824642 49950 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.824631040+00:00
I0314 19:33:46.824679 49948 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.824668928+00:00
I0314 19:33:46.824774 49948 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.824765952+00:00
I0314 19:33:46.824802 49954 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.824794880+00:00
I0314 19:33:46.824837 49948 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0314 19:33:46.826563 49948 leveldb.cpp:341] Persisting action (261 bytes) to leveldb took 1.693759ms
I0314 19:33:46.826598 49948 replica.cpp:712] Persisted action at 1
I0314 19:33:46.826619 49948 replica.cpp:697] Replica learned APPEND action at position 1
I0314 19:33:46.826730 49951 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.826721024+00:00
I0314 19:33:46.826931 49960 process.cpp:2494] Resuming (5457)@172.31.14.224:50909 at 2016-03-14 19:33:46.826920960+00:00
I0314 19:33:46.827265 49949 process.cpp:2494] Resuming __latch__(1952)@172.31.14.224:50909 at 2016-03-14 19:33:46.827256064+00:00
I0314 19:33:46.827302 49949 process.cpp:2599] Cleaning up __latch__(1952)@172.31.14.224:50909
I0314 19:33:46.827394 49955 process.cpp:2494] Resuming registrar(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.827382016+00:00
I0314 19:33:46.827425 49956 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.827414016+00:00
I0314 19:33:46.827396 49953 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.827386112+00:00
I0314 19:33:46.827514 49955 registrar.cpp:484] Successfully updated the 'registry' in 6624us
I0314 19:33:46.827661 49955 registrar.cpp:370] Successfully recovered registrar
I0314 19:33:46.827667 49962 process.cpp:2494] Resuming log-writer(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.827659008+00:00
I0314 19:33:46.827741 49962 log.cpp:702] Attempting to truncate the log to 1
I0314 19:33:46.827848 49958 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:46.827838976+00:00
I0314 19:33:46.827860 49955 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.827852032+00:00
I0314 19:33:46.827950 49953 process.cpp:2494] Resuming __latch__(1949)@172.31.14.224:50909 at 2016-03-14 19:33:46.827942912+00:00
I0314 19:33:46.827987 49953 process.cpp:2599] Cleaning up __latch__(1949)@172.31.14.224:50909
I0314 19:33:46.827986 49955 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0314 19:33:46.828043 49962 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.828035072+00:00
I0314 19:33:46.828095 49950 process.cpp:2494] Resuming __waiter__(805)@172.31.14.224:50909 at 2016-03-14 19:33:46.828086016+00:00
I0314 19:33:46.828140 49948 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.828129024+00:00
I0314 19:33:46.828352 49955 process.cpp:2484] Spawned process log-write(393)@172.31.14.224:50909
I0314 19:33:46.828397 49962 process.cpp:2494] Resuming (5455)@172.31.14.224:50909 at 2016-03-14 19:33:46.828389888+00:00
I0314 19:33:46.828361 49947 process.cpp:2494] Resuming log-write(393)@172.31.14.224:50909 at 2016-03-14 19:33:46.828353024+00:00
I0314 19:33:46.828446 49962 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0314 19:33:46.828353 49958 master.cpp:1521] Recovered 0 slaves from the Registry (201B) ; allowing 10mins for slaves to re-register
I0314 19:33:46.828357 49954 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.828347904+00:00
I0314 19:33:46.828364 49950 process.cpp:2599] Cleaning up __waiter__(805)@172.31.14.224:50909
I0314 19:33:46.828502 49955 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.828495104+00:00
I0314 19:33:46.828598 49954 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.828589056+00:00
I0314 19:33:46.828658 49933 clock.cpp:331] Clock paused at 0x3e84f40
I0314 19:33:46.828738 49949 process.cpp:2494] Resuming log-write(393)@172.31.14.224:50909 at 2016-03-14 19:33:46.828645888+00:00
I0314 19:33:46.828866 49950 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.828645888+00:00
I0314 19:33:46.828948 49950 clock.cpp:435] Clock of (5465)@172.31.14.224:50909 updated to 2016-03-14 19:33:46.828645888+00:00
I0314 19:33:46.829041 49950 process.cpp:2484] Spawned process (5465)@172.31.14.224:50909
I0314 19:33:46.829054 49949 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.828645888+00:00
I0314 19:33:46.829062 49957 process.cpp:2494] Resuming (5465)@172.31.14.224:50909 at 2016-03-14 19:33:46.828645888+00:00
I0314 19:33:46.829145 49947 process.cpp:2494] Resuming log-write(393)@172.31.14.224:50909 at 2016-03-14 19:33:46.828645888+00:00
I0314 19:33:46.829196 49957 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.828645888+00:00
I0314 19:33:46.829260 49957 replica.cpp:537] Replica received write request for position 2 from (5465)@172.31.14.224:50909
I0314 19:33:46.831053 49957 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 1.750746ms
I0314 19:33:46.831087 49957 replica.cpp:712] Persisted action at 2
I0314 19:33:46.831151 49957 process.cpp:2494] Resuming (5465)@172.31.14.224:50909 at 2016-03-14 19:33:46.828645888+00:00
I0314 19:33:46.831239 49961 process.cpp:2494] Resuming log-write(393)@172.31.14.224:50909 at 2016-03-14 19:33:46.828645888+00:00
I0314 19:33:46.831266 49957 process.cpp:2599] Cleaning up (5465)@172.31.14.224:50909
I0314 19:33:46.831331 49950 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.828645888+00:00
I0314 19:33:46.831370 49951 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.828645888+00:00
I0314 19:33:46.831398 49958 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.828645888+00:00
I0314 19:33:46.831425 49961 process.cpp:2599] Cleaning up log-write(393)@172.31.14.224:50909
I0314 19:33:46.831496 49958 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.828645888+00:00
I0314 19:33:46.831545 49950 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.828645888+00:00
I0314 19:33:46.831550 49954 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.828645888+00:00
I0314 19:33:46.831773 49960 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.828645888+00:00
I0314 19:33:46.831867 49960 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0314 19:33:46.831884 49959 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.828645888+00:00
I0314 19:33:46.833694 49960 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 1.793357ms
I0314 19:33:46.833752 49960 leveldb.cpp:399] Deleting ~1 keys from leveldb took 24183ns
I0314 19:33:46.833781 49960 replica.cpp:712] Persisted action at 2
I0314 19:33:46.833801 49960 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0314 19:33:46.833907 49961 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.828645888+00:00
I0314 19:33:46.834084 49956 process.cpp:2494] Resuming (5457)@172.31.14.224:50909 at 2016-03-14 19:33:46.828645888+00:00
I0314 19:33:46.838836 49933 clock.cpp:361] Clock resumed at 0x3e6dce0
I0314 19:33:46.839920 49933 process.cpp:2484] Spawned process fetcher(79)@172.31.14.224:50909
I0314 19:33:46.839941 49947 process.cpp:2494] Resuming fetcher(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.839931904+00:00
I0314 19:33:46.840056 49933 containerizer.cpp:149] Using isolation: cgroups/mem,filesystem/posix
I0314 19:33:46.840154 49933 process.cpp:2484] Spawned process (5466)@172.31.14.224:50909
I0314 19:33:46.840169 49962 process.cpp:2494] Resuming (5466)@172.31.14.224:50909 at 2016-03-14 19:33:46.840160000+00:00
I0314 19:33:46.847270 49933 linux_launcher.cpp:101] Using /sys/fs/cgroup/freezer as the freezer hierarchy for the Linux launcher
I0314 19:33:46.847592 49933 process.cpp:2484] Spawned process (5467)@172.31.14.224:50909
I0314 19:33:46.847614 49955 process.cpp:2494] Resuming (5467)@172.31.14.224:50909 at 2016-03-14 19:33:46.847603968+00:00
I0314 19:33:46.847757 49956 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:46.847749120+00:00
I0314 19:33:46.847894 49933 process.cpp:2484] Spawned process (5468)@172.31.14.224:50909
I0314 19:33:46.847903 49955 process.cpp:2494] Resuming (5468)@172.31.14.224:50909 at 2016-03-14 19:33:46.847892992+00:00
I0314 19:33:46.848143 49933 process.cpp:2484] Spawned process (5469)@172.31.14.224:50909
I0314 19:33:46.848142 49961 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:46.848133888+00:00
I0314 19:33:46.848156 49950 process.cpp:2494] Resuming (5469)@172.31.14.224:50909 at 2016-03-14 19:33:46.848146944+00:00
I0314 19:33:46.857857 49933 process.cpp:2484] Spawned process (5470)@172.31.14.224:50909
I0314 19:33:46.857874 49957 process.cpp:2494] Resuming (5470)@172.31.14.224:50909 at 2016-03-14 19:33:46.857864960+00:00
I0314 19:33:46.857939 49957 process.cpp:2484] Spawned process (5471)@172.31.14.224:50909
I0314 19:33:46.857957 49951 process.cpp:2494] Resuming (5471)@172.31.14.224:50909 at 2016-03-14 19:33:46.857946880+00:00
I0314 19:33:46.858050 49951 process.cpp:2599] Cleaning up (5471)@172.31.14.224:50909
I0314 19:33:46.858139 49961 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.858129920+00:00
I0314 19:33:46.858160 49957 process.cpp:2599] Cleaning up (5470)@172.31.14.224:50909
I0314 19:33:46.858225 49962 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.858215936+00:00
I0314 19:33:46.858932 49933 process.cpp:2484] Spawned process (5472)@172.31.14.224:50909
I0314 19:33:46.858947 49959 process.cpp:2494] Resuming (5472)@172.31.14.224:50909 at 2016-03-14 19:33:46.858938880+00:00
I0314 19:33:46.859009 49959 process.cpp:2484] Spawned process (5473)@172.31.14.224:50909
I0314 19:33:46.859012 49953 process.cpp:2494] Resuming (5473)@172.31.14.224:50909 at 2016-03-14 19:33:46.859003904+00:00
I0314 19:33:46.859132 49953 process.cpp:2599] Cleaning up (5473)@172.31.14.224:50909
I0314 19:33:46.859230 49956 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.859220992+00:00
I0314 19:33:46.859247 49959 process.cpp:2599] Cleaning up (5472)@172.31.14.224:50909
I0314 19:33:46.859328 49962 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.859319040+00:00
I0314 19:33:46.860015 49933 process.cpp:2484] Spawned process (5474)@172.31.14.224:50909
I0314 19:33:46.860033 49954 process.cpp:2494] Resuming (5474)@172.31.14.224:50909 at 2016-03-14 19:33:46.860024064+00:00
I0314 19:33:46.860091 49954 process.cpp:2484] Spawned process (5475)@172.31.14.224:50909
I0314 19:33:46.860096 49962 process.cpp:2494] Resuming (5475)@172.31.14.224:50909 at 2016-03-14 19:33:46.860087040+00:00
I0314 19:33:46.860209 49962 process.cpp:2599] Cleaning up (5475)@172.31.14.224:50909
I0314 19:33:46.860306 49948 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.860294912+00:00
I0314 19:33:46.860324 49954 process.cpp:2599] Cleaning up (5474)@172.31.14.224:50909
I0314 19:33:46.860404 49955 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.860396032+00:00
I0314 19:33:46.860599 49933 process.cpp:2484] Spawned process (5476)@172.31.14.224:50909
I0314 19:33:46.860616 49951 process.cpp:2494] Resuming (5476)@172.31.14.224:50909 at 2016-03-14 19:33:46.860608000+00:00
I0314 19:33:46.860792 49933 process.cpp:2484] Spawned process (5477)@172.31.14.224:50909
I0314 19:33:46.860810 49952 process.cpp:2494] Resuming (5477)@172.31.14.224:50909 at 2016-03-14 19:33:46.860797952+00:00
I0314 19:33:46.860985 49960 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:46.860976128+00:00
I0314 19:33:46.861007 49933 process.cpp:2484] Spawned process (5478)@172.31.14.224:50909
I0314 19:33:46.861016 49962 process.cpp:2494] Resuming (5478)@172.31.14.224:50909 at 2016-03-14 19:33:46.861005056+00:00
I0314 19:33:46.862203 49933 process.cpp:2484] Spawned process standalone-master-detector(236)@172.31.14.224:50909
I0314 19:33:46.862222 49951 process.cpp:2494] Resuming standalone-master-detector(236)@172.31.14.224:50909 at 2016-03-14 19:33:46.862213888+00:00
I0314 19:33:46.862316 49933 process.cpp:2484] Spawned process (5479)@172.31.14.224:50909
I0314 19:33:46.862321 49953 process.cpp:2494] Resuming (5479)@172.31.14.224:50909 at 2016-03-14 19:33:46.862311936+00:00
I0314 19:33:46.862517 49933 process.cpp:2484] Spawned process (5480)@172.31.14.224:50909
I0314 19:33:46.862535 49960 process.cpp:2494] Resuming (5480)@172.31.14.224:50909 at 2016-03-14 19:33:46.862526976+00:00
I0314 19:33:46.862903 49956 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:46.862895104+00:00
I0314 19:33:46.863370 49933 process.cpp:2484] Spawned process __limiter__(79)@172.31.14.224:50909
I0314 19:33:46.863387 49949 process.cpp:2494] Resuming __limiter__(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.863378944+00:00
I0314 19:33:46.863432 49949 process.cpp:2494] Resuming monitor@172.31.14.224:50909 at 2016-03-14 19:33:46.863427072+00:00
I0314 19:33:46.863433 49933 process.cpp:2484] Spawned process monitor@172.31.14.224:50909
I0314 19:33:46.863567 49960 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.863560960+00:00
I0314 19:33:46.863564 49933 process.cpp:2484] Spawned process slave(79)@172.31.14.224:50909
I0314 19:33:46.863622 49960 slave.cpp:193] Slave started on 79)@172.31.14.224:50909
I0314 19:33:46.863564 49958 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.863555072+00:00
I0314 19:33:46.863646 49960 slave.cpp:194] Flags at startup: --appc_simple_discovery_uri_prefix="http://" --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_test_4dc96c1d-9ea2-495d-b529-5cb6d56fd931" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/MemoryPressureMesosTest_CGROUPS_ROOT_Statistics_rUXQlo/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/mesos/store/docker" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/MemoryPressureMesosTest_CGROUPS_ROOT_Statistics_rUXQlo/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="cgroups/mem" --launcher_dir="/mnt/src/mesos-test/build-0.28.0-rc2/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_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/MemoryPressureMesosTest_CGROUPS_ROOT_Statistics_rUXQlo"
I0314 19:33:46.863916 49960 credentials.hpp:83] Loading credential for authentication from '/tmp/MemoryPressureMesosTest_CGROUPS_ROOT_Statistics_rUXQlo/credential'
I0314 19:33:46.864070 49960 slave.cpp:324] Slave using credential for: test-principal
I0314 19:33:46.864146 49960 process.cpp:2484] Spawned process (5481)@172.31.14.224:50909
I0314 19:33:46.864166 49955 process.cpp:2494] Resuming (5481)@172.31.14.224:50909 at 2016-03-14 19:33:46.864158976+00:00
I0314 19:33:46.864217 49960 process.cpp:2484] Spawned process (5482)@172.31.14.224:50909
I0314 19:33:46.864220 49948 process.cpp:2494] Resuming (5482)@172.31.14.224:50909 at 2016-03-14 19:33:46.864212992+00:00
I0314 19:33:46.864270 49960 resources.cpp:572] Parsing resources as JSON failed: cpus:2;mem:1024;disk:1024;ports:[31000-32000]
Trying semicolon-delimited string format instead
I0314 19:33:46.864821 49960 slave.cpp:464] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0314 19:33:46.864889 49960 slave.cpp:472] Slave attributes: [  ]
I0314 19:33:46.864905 49960 slave.cpp:477] Slave hostname: ip-172-31-14-224.us-west-1.compute.internal
I0314 19:33:46.865006 49951 process.cpp:2494] Resuming (5480)@172.31.14.224:50909 at 2016-03-14 19:33:46.864997120+00:00
I0314 19:33:46.865253 49933 process.cpp:2484] Spawned process __latch__(1953)@172.31.14.224:50909
I0314 19:33:46.865279 49947 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.865272064+00:00
I0314 19:33:46.865286 49957 process.cpp:2494] Resuming __latch__(1953)@172.31.14.224:50909 at 2016-03-14 19:33:46.865275904+00:00
I0314 19:33:46.865298 49953 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.865289984+00:00
I0314 19:33:46.865514 49959 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.865506048+00:00
I0314 19:33:46.865706 49933 pid.cpp:93] Attempting to parse 'master@172.31.14.224:50909' into a PID
I0314 19:33:46.865746 49960 process.cpp:2484] Spawned process __async_executor__(79)@172.31.14.224:50909
I0314 19:33:46.865747 49948 process.cpp:2494] Resuming __async_executor__(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.865741056+00:00
I0314 19:33:46.865828 49956 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.865817088+00:00
I0314 19:33:46.865841 49958 process.cpp:2494] Resuming __async_executor__(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.865829888+00:00
I0314 19:33:46.865941 49958 state.cpp:58] Recovering state from '/tmp/MemoryPressureMesosTest_CGROUPS_ROOT_Statistics_rUXQlo/meta'
I0314 19:33:46.866051 49952 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.866043904+00:00
I0314 19:33:46.866063 49958 process.cpp:2599] Cleaning up __async_executor__(79)@172.31.14.224:50909
I0314 19:33:46.866163 49957 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.866155008+00:00
I0314 19:33:46.866173 49961 process.cpp:2494] Resuming (5480)@172.31.14.224:50909 at 2016-03-14 19:33:46.866167040+00:00
I0314 19:33:46.866204 49952 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.866195968+00:00
I0314 19:33:46.866240 49961 status_update_manager.cpp:200] Recovering status update manager
I0314 19:33:46.866428 49933 process.cpp:2484] Spawned process standalone-master-detector(237)@172.31.14.224:50909
I0314 19:33:46.866432 49959 process.cpp:2494] Resuming standalone-master-detector(237)@172.31.14.224:50909 at 2016-03-14 19:33:46.866423040+00:00
I0314 19:33:46.866438 49956 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.866429952+00:00
I0314 19:33:46.866601 49962 process.cpp:2494] Resuming (5478)@172.31.14.224:50909 at 2016-03-14 19:33:46.866594048+00:00
I0314 19:33:46.866657 49962 containerizer.cpp:407] Recovering containerizer
I0314 19:33:46.866819 49956 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:46.866810880+00:00
I0314 19:33:46.866842 49933 sched.cpp:222] Version: 0.28.0
I0314 19:33:46.866935 49933 process.cpp:2484] Spawned process scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909
I0314 19:33:46.866956 49954 process.cpp:2494] Resuming scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909 at 2016-03-14 19:33:46.866947072+00:00
I0314 19:33:46.867041 49953 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.867033088+00:00
I0314 19:33:46.867065 49960 process.cpp:2494] Resuming __latch__(1954)@172.31.14.224:50909 at 2016-03-14 19:33:46.867054080+00:00
I0314 19:33:46.867046 49933 process.cpp:2484] Spawned process __latch__(1954)@172.31.14.224:50909
I0314 19:33:46.867199 49956 process.cpp:2494] Resuming standalone-master-detector(237)@172.31.14.224:50909 at 2016-03-14 19:33:46.867191040+00:00
I0314 19:33:46.867197 49933 process.cpp:2484] Spawned process __waiter__(806)@172.31.14.224:50909
I0314 19:33:46.867207 49957 process.cpp:2494] Resuming __waiter__(806)@172.31.14.224:50909 at 2016-03-14 19:33:46.867198976+00:00
I0314 19:33:46.867377 49952 process.cpp:2494] Resuming scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909 at 2016-03-14 19:33:46.867366912+00:00
I0314 19:33:46.867457 49952 sched.cpp:326] New master detected at master@172.31.14.224:50909
I0314 19:33:46.867498 49952 pid.cpp:93] Attempting to parse 'master@172.31.14.224:50909' into a PID
I0314 19:33:46.867583 49952 sched.cpp:382] Authenticating with master master@172.31.14.224:50909
I0314 19:33:46.867620 49952 sched.cpp:389] Using default CRAM-MD5 authenticatee
I0314 19:33:46.867657 49952 pid.cpp:93] Attempting to parse 'master@172.31.14.224:50909' into a PID
I0314 19:33:46.867759 49952 process.cpp:2484] Spawned process crammd5_authenticatee(157)@172.31.14.224:50909
I0314 19:33:46.867777 49954 process.cpp:2494] Resuming crammd5_authenticatee(157)@172.31.14.224:50909 at 2016-03-14 19:33:46.867769088+00:00
I0314 19:33:46.867817 49950 process.cpp:2494] Resuming (5477)@172.31.14.224:50909 at 2016-03-14 19:33:46.867809024+00:00
I0314 19:33:46.867851 49957 process.cpp:2494] Resuming (5476)@172.31.14.224:50909 at 2016-03-14 19:33:46.867840000+00:00
I0314 19:33:46.867892 49954 authenticatee.cpp:121] Creating new client SASL connection
I0314 19:33:46.867936 49959 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.867930112+00:00
I0314 19:33:46.867952 49961 process.cpp:2494] Resuming standalone-master-detector(237)@172.31.14.224:50909 at 2016-03-14 19:33:46.867942912+00:00
I0314 19:33:46.867959 49958 process.cpp:2494] Resuming (5483)@172.31.14.224:50909 at 2016-03-14 19:33:46.867947008+00:00
I0314 19:33:46.867943 49962 process.cpp:2484] Spawned process (5483)@172.31.14.224:50909
I0314 19:33:46.868371 49955 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:46.868363008+00:00
I0314 19:33:46.868420 49954 process.cpp:2494] Resuming reaper(1)@172.31.14.224:50909 at 2016-03-14 19:33:46.868411904+00:00
I0314 19:33:46.868443 49955 pid.cpp:93] Attempting to parse 'scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909' into a PID
I0314 19:33:46.868496 49955 master.cpp:5495] Authenticating scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909
I0314 19:33:46.868559 49958 process.cpp:2494] Resuming crammd5_authenticator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.868549120+00:00
I0314 19:33:46.868628 49958 authenticator.cpp:413] Starting authentication session for crammd5_authenticatee(157)@172.31.14.224:50909
I0314 19:33:46.868731 49958 process.cpp:2484] Spawned process crammd5_authenticator_session(157)@172.31.14.224:50909
I0314 19:33:46.868752 49949 process.cpp:2494] Resuming crammd5_authenticator_session(157)@172.31.14.224:50909 at 2016-03-14 19:33:46.868742912+00:00
I0314 19:33:46.868880 49949 authenticator.cpp:98] Creating new server SASL connection
I0314 19:33:46.869094 49957 process.cpp:2494] Resuming (5483)@172.31.14.224:50909 at 2016-03-14 19:33:46.869086976+00:00
I0314 19:33:46.869245 49958 process.cpp:2494] Resuming (5478)@172.31.14.224:50909 at 2016-03-14 19:33:46.869233920+00:00
I0314 19:33:46.869252 49947 process.cpp:2494] Resuming crammd5_authenticatee(157)@172.31.14.224:50909 at 2016-03-14 19:33:46.869243904+00:00
I0314 19:33:46.869268 49957 process.cpp:2599] Cleaning up (5483)@172.31.14.224:50909
I0314 19:33:46.869359 49947 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
I0314 19:33:46.869366 49955 process.cpp:2494] Resuming (5469)@172.31.14.224:50909 at 2016-03-14 19:33:46.869357056+00:00
I0314 19:33:46.869384 49947 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I0314 19:33:46.869495 49947 process.cpp:2494] Resuming crammd5_authenticator_session(157)@172.31.14.224:50909 at 2016-03-14 19:33:46.869488128+00:00
I0314 19:33:46.869524 49962 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.869513984+00:00
I0314 19:33:46.869551 49947 authenticator.cpp:203] Received SASL authentication start
I0314 19:33:46.869556 49951 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.869547008+00:00
I0314 19:33:46.869592 49947 authenticator.cpp:325] Authentication requires more steps
I0314 19:33:46.869681 49947 process.cpp:2494] Resuming (5484)@172.31.14.224:50909 at 2016-03-14 19:33:46.869675008+00:00
I0314 19:33:46.869689 49956 process.cpp:2494] Resuming crammd5_authenticatee(157)@172.31.14.224:50909 at 2016-03-14 19:33:46.869680128+00:00
I0314 19:33:46.869809 49947 process.cpp:2599] Cleaning up (5484)@172.31.14.224:50909
I0314 19:33:46.869815 49956 authenticatee.cpp:258] Received SASL authentication step
I0314 19:33:46.869853 49955 process.cpp:2484] Spawned process (5484)@172.31.14.224:50909
I0314 19:33:46.869876 49951 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.869867008+00:00
I0314 19:33:46.869915 49949 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.869905920+00:00
I0314 19:33:46.870003 49955 provisioner.cpp:245] Provisioner recovery complete
I0314 19:33:46.870005 49957 process.cpp:2494] Resuming crammd5_authenticator_session(157)@172.31.14.224:50909 at 2016-03-14 19:33:46.869995008+00:00
I0314 19:33:46.870095 49948 process.cpp:2494] Resuming (5478)@172.31.14.224:50909 at 2016-03-14 19:33:46.870086912+00:00
I0314 19:33:46.870218 49952 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.870209024+00:00
I0314 19:33:46.870309 49957 authenticator.cpp:231] Received SASL authentication step
I0314 19:33:46.870333 49952 slave.cpp:4565] Finished recovery
I0314 19:33:46.870347 49957 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: 'ip-172-31-14-224.us-west-1.compute.internal' server FQDN: 'ip-172-31-14-224.us-west-1.compute.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0314 19:33:46.870363 49957 auxprop.cpp:179] Looking up auxiliary property '*userPassword'
I0314 19:33:46.870424 49957 auxprop.cpp:179] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0314 19:33:46.870463 49957 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: 'ip-172-31-14-224.us-west-1.compute.internal' server FQDN: 'ip-172-31-14-224.us-west-1.compute.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0314 19:33:46.870494 49957 auxprop.cpp:129] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0314 19:33:46.870506 49957 auxprop.cpp:129] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0314 19:33:46.870529 49957 authenticator.cpp:317] Authentication success
I0314 19:33:46.870584 49952 slave.cpp:4737] Querying resource estimator for oversubscribable resources
I0314 19:33:46.870591 49948 process.cpp:2494] Resuming standalone-master-detector(236)@172.31.14.224:50909 at 2016-03-14 19:33:46.870582016+00:00
I0314 19:33:46.870618 49958 process.cpp:2494] Resuming crammd5_authenticatee(157)@172.31.14.224:50909 at 2016-03-14 19:33:46.870606080+00:00
I0314 19:33:46.870679 49953 process.cpp:2494] Resuming (5481)@172.31.14.224:50909 at 2016-03-14 19:33:46.870670080+00:00
I0314 19:33:46.870699 49954 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:46.870689024+00:00
I0314 19:33:46.870707 49958 authenticatee.cpp:298] Authentication success
I0314 19:33:46.870769 49950 process.cpp:2494] Resuming crammd5_authenticator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.870759936+00:00
I0314 19:33:46.870769 49954 master.cpp:5525] Successfully authenticated principal 'test-principal' at scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909
I0314 19:33:46.870832 49955 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.870822912+00:00
I0314 19:33:46.870846 49962 process.cpp:2494] Resuming scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909 at 2016-03-14 19:33:46.870835968+00:00
I0314 19:33:46.870926 49950 authenticator.cpp:431] Authentication session cleanup for crammd5_authenticatee(157)@172.31.14.224:50909
I0314 19:33:46.870950 49954 process.cpp:2494] Resuming crammd5_authenticatee(157)@172.31.14.224:50909 at 2016-03-14 19:33:46.870942976+00:00
I0314 19:33:46.870962 49957 process.cpp:2494] Resuming (5480)@172.31.14.224:50909 at 2016-03-14 19:33:46.870925056+00:00
I0314 19:33:46.870995 49947 process.cpp:2494] Resuming crammd5_authenticator_session(157)@172.31.14.224:50909 at 2016-03-14 19:33:46.870987008+00:00
I0314 19:33:46.870982 49954 process.cpp:2599] Cleaning up crammd5_authenticatee(157)@172.31.14.224:50909
I0314 19:33:46.871028 49947 process.cpp:2599] Cleaning up crammd5_authenticator_session(157)@172.31.14.224:50909
I0314 19:33:46.871052 49955 pid.cpp:93] Attempting to parse 'master@172.31.14.224:50909' into a PID
I0314 19:33:46.871074 49957 status_update_manager.cpp:174] Pausing sending status updates
I0314 19:33:46.871098 49955 slave.cpp:796] New master detected at master@172.31.14.224:50909
I0314 19:33:46.871078 49948 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.871069952+00:00
I0314 19:33:46.871184 49962 sched.cpp:471] Successfully authenticated with master master@172.31.14.224:50909
I0314 19:33:46.871212 49962 sched.cpp:776] Sending SUBSCRIBE call to master@172.31.14.224:50909
I0314 19:33:46.871237 49962 pid.cpp:93] Attempting to parse 'master@172.31.14.224:50909' into a PID
I0314 19:33:46.871240 49955 slave.cpp:859] Authenticating with master master@172.31.14.224:50909
I0314 19:33:46.871271 49955 slave.cpp:864] Using default CRAM-MD5 authenticatee
I0314 19:33:46.871306 49962 sched.cpp:809] Will retry registration in 1.564503572secs if necessary
I0314 19:33:46.871340 49949 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:46.871328000+00:00
I0314 19:33:46.871376 49957 process.cpp:2494] Resuming crammd5_authenticatee(158)@172.31.14.224:50909 at 2016-03-14 19:33:46.871367936+00:00
I0314 19:33:46.871352 49955 process.cpp:2484] Spawned process crammd5_authenticatee(158)@172.31.14.224:50909
I0314 19:33:46.871476 49949 master.cpp:2231] Received SUBSCRIBE call for framework 'default' at scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909
I0314 19:33:46.871479 49958 process.cpp:2494] Resuming crammd5_authenticatee(158)@172.31.14.224:50909 at 2016-03-14 19:33:46.871470080+00:00
I0314 19:33:46.871521 49955 slave.cpp:832] Detecting new master
I0314 19:33:46.871577 49958 authenticatee.cpp:121] Creating new client SASL connection
I0314 19:33:46.871558 49949 master.cpp:1750] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0314 19:33:46.871681 49954 process.cpp:2494] Resuming standalone-master-detector(236)@172.31.14.224:50909 at 2016-03-14 19:33:46.871670016+00:00
I0314 19:33:46.871704 49955 slave.cpp:4751] Received oversubscribable resources  from the resource estimator
I0314 19:33:46.871695 49953 process.cpp:2494] Resuming authorizer(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.871686912+00:00
I0314 19:33:46.871878 49947 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:46.871870976+00:00
I0314 19:33:46.871939 49947 master.cpp:2302] Subscribing framework default with checkpointing disabled and capabilities [  ]
I0314 19:33:46.872141 49953 process.cpp:2494] Resuming (5455)@172.31.14.224:50909 at 2016-03-14 19:33:46.872133120+00:00
I0314 19:33:46.872192 49948 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:46.872184064+00:00
I0314 19:33:46.872241 49955 process.cpp:2494] Resuming scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909 at 2016-03-14 19:33:46.872231936+00:00
I0314 19:33:46.872270 49953 hierarchical.cpp:265] Added framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:46.872290 49947 pid.cpp:93] Attempting to parse 'slave(79)@172.31.14.224:50909' into a PID
I0314 19:33:46.872325 49947 master.cpp:5495] Authenticating slave(79)@172.31.14.224:50909
I0314 19:33:46.872328 49955 pid.cpp:93] Attempting to parse 'master@172.31.14.224:50909' into a PID
I0314 19:33:46.872337 49953 hierarchical.cpp:1453] No resources available to allocate!
I0314 19:33:46.872395 49955 sched.cpp:703] Framework registered with dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:46.872428 49953 hierarchical.cpp:1548] No inverse offers to send out!
I0314 19:33:46.872411 49952 process.cpp:2494] Resuming crammd5_authenticator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.872401920+00:00
I0314 19:33:46.872457 49955 sched.cpp:717] Scheduler::registered took 16068ns
I0314 19:33:46.872480 49952 authenticator.cpp:413] Starting authentication session for crammd5_authenticatee(158)@172.31.14.224:50909
I0314 19:33:46.872455 49953 hierarchical.cpp:1130] Performed allocation for 0 slaves in 156015ns
I0314 19:33:46.872576 49948 process.cpp:2494] Resuming crammd5_authenticator_session(158)@172.31.14.224:50909 at 2016-03-14 19:33:46.872568064+00:00
I0314 19:33:46.872581 49952 process.cpp:2484] Spawned process crammd5_authenticator_session(158)@172.31.14.224:50909
I0314 19:33:46.872750 49948 authenticator.cpp:98] Creating new server SASL connection
I0314 19:33:46.873114 49957 process.cpp:2494] Resuming crammd5_authenticatee(158)@172.31.14.224:50909 at 2016-03-14 19:33:46.873105920+00:00
I0314 19:33:46.873178 49957 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
I0314 19:33:46.873219 49957 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I0314 19:33:46.873275 49953 process.cpp:2494] Resuming crammd5_authenticator_session(158)@172.31.14.224:50909 at 2016-03-14 19:33:46.873266944+00:00
I0314 19:33:46.873334 49953 authenticator.cpp:203] Received SASL authentication start
I0314 19:33:46.873381 49953 authenticator.cpp:325] Authentication requires more steps
I0314 19:33:46.873442 49953 process.cpp:2494] Resuming crammd5_authenticatee(158)@172.31.14.224:50909 at 2016-03-14 19:33:46.873435904+00:00
I0314 19:33:46.873497 49953 authenticatee.cpp:258] Received SASL authentication step
I0314 19:33:46.873567 49953 process.cpp:2494] Resuming crammd5_authenticator_session(158)@172.31.14.224:50909 at 2016-03-14 19:33:46.873559040+00:00
I0314 19:33:46.873631 49953 authenticator.cpp:231] Received SASL authentication step
I0314 19:33:46.873663 49953 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: 'ip-172-31-14-224.us-west-1.compute.internal' server FQDN: 'ip-172-31-14-224.us-west-1.compute.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0314 19:33:46.873680 49953 auxprop.cpp:179] Looking up auxiliary property '*userPassword'
I0314 19:33:46.873709 49953 auxprop.cpp:179] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0314 19:33:46.873742 49953 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: 'ip-172-31-14-224.us-west-1.compute.internal' server FQDN: 'ip-172-31-14-224.us-west-1.compute.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0314 19:33:46.873764 49953 auxprop.cpp:129] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0314 19:33:46.873775 49953 auxprop.cpp:129] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0314 19:33:46.873791 49953 authenticator.cpp:317] Authentication success
I0314 19:33:46.873852 49954 process.cpp:2494] Resuming crammd5_authenticatee(158)@172.31.14.224:50909 at 2016-03-14 19:33:46.873843968+00:00
I0314 19:33:46.873865 49950 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:46.873857024+00:00
I0314 19:33:46.873909 49956 process.cpp:2494] Resuming crammd5_authenticator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.873897984+00:00
I0314 19:33:46.873919 49954 authenticatee.cpp:298] Authentication success
I0314 19:33:46.873973 49956 authenticator.cpp:431] Authentication session cleanup for crammd5_authenticatee(158)@172.31.14.224:50909
I0314 19:33:46.873929 49950 master.cpp:5525] Successfully authenticated principal 'test-principal' at slave(79)@172.31.14.224:50909
I0314 19:33:46.874040 49950 process.cpp:2494] Resuming crammd5_authenticator_session(158)@172.31.14.224:50909 at 2016-03-14 19:33:46.874032128+00:00
I0314 19:33:46.874055 49949 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.874045952+00:00
I0314 19:33:46.874096 49950 process.cpp:2599] Cleaning up crammd5_authenticator_session(158)@172.31.14.224:50909
I0314 19:33:46.874168 49955 process.cpp:2494] Resuming crammd5_authenticatee(158)@172.31.14.224:50909 at 2016-03-14 19:33:46.874159104+00:00
I0314 19:33:46.874178 49954 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.874170112+00:00
I0314 19:33:46.874213 49955 process.cpp:2599] Cleaning up crammd5_authenticatee(158)@172.31.14.224:50909
I0314 19:33:46.874325 49952 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.874316032+00:00
I0314 19:33:46.874361 49949 slave.cpp:927] Successfully authenticated with master master@172.31.14.224:50909
I0314 19:33:46.874476 49949 slave.cpp:1321] Will retry registration in 390113ns if necessary
I0314 19:33:46.874469 49960 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:46.874460928+00:00
I0314 19:33:46.874646 49960 master.cpp:4206] Registering slave at slave(79)@172.31.14.224:50909 (ip-172-31-14-224.us-west-1.compute.internal) with id dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0
I0314 19:33:46.874804 49956 process.cpp:2494] Resuming registrar(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.874796032+00:00
I0314 19:33:46.875026 49956 registrar.cpp:439] Applied 1 operations in 42078ns; attempting to update the 'registry'
I0314 19:33:46.875216 49948 process.cpp:2494] Resuming (5457)@172.31.14.224:50909 at 2016-03-14 19:33:46.875207936+00:00
I0314 19:33:46.875380 49958 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.875369984+00:00
I0314 19:33:46.875399 49961 process.cpp:2494] Resuming __latch__(1955)@172.31.14.224:50909 at 2016-03-14 19:33:46.875388928+00:00
I0314 19:33:46.875388 49956 process.cpp:2484] Spawned process __latch__(1955)@172.31.14.224:50909
I0314 19:33:46.875571 49954 process.cpp:2494] Resuming log-writer(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.875561984+00:00
I0314 19:33:46.875627 49954 log.cpp:683] Attempting to append 440 bytes to the log
I0314 19:33:46.875737 49955 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.875727104+00:00
I0314 19:33:46.875771 49947 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.875762944+00:00
I0314 19:33:46.875792 49955 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3
I0314 19:33:46.875906 49955 process.cpp:2484] Spawned process log-write(394)@172.31.14.224:50909
I0314 19:33:46.875921 49961 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.875912960+00:00
I0314 19:33:46.875936 49956 process.cpp:2494] Resuming log-write(394)@172.31.14.224:50909 at 2016-03-14 19:33:46.875924992+00:00
I0314 19:33:46.875957 49954 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:46.875945984+00:00
I0314 19:33:46.876015 49959 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.876006912+00:00
I0314 19:33:46.876113 49953 process.cpp:2494] Resuming log-write(394)@172.31.14.224:50909 at 2016-03-14 19:33:46.876101888+00:00
I0314 19:33:46.876232 49947 slave.cpp:1321] Will retry registration in 25.887546ms if necessary
I0314 19:33:46.876240 49950 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.876227072+00:00
I0314 19:33:46.876344 49954 master.cpp:4194] Ignoring register slave message from slave(79)@172.31.14.224:50909 (ip-172-31-14-224.us-west-1.compute.internal) as admission is already in progress
I0314 19:33:46.876384 49950 process.cpp:2484] Spawned process (5485)@172.31.14.224:50909
I0314 19:33:46.876394 49961 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.876386048+00:00
I0314 19:33:46.876402 49954 process.cpp:2494] Resuming (5485)@172.31.14.224:50909 at 2016-03-14 19:33:46.876392960+00:00
I0314 19:33:46.876477 49960 process.cpp:2494] Resuming log-write(394)@172.31.14.224:50909 at 2016-03-14 19:33:46.876464896+00:00
I0314 19:33:46.876505 49958 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.876497920+00:00
I0314 19:33:46.876559 49958 replica.cpp:537] Replica received write request for position 3 from (5485)@172.31.14.224:50909
I0314 19:33:46.877193 49958 leveldb.cpp:341] Persisting action (459 bytes) to leveldb took 597319ns
I0314 19:33:46.877223 49958 replica.cpp:712] Persisted action at 3
I0314 19:33:46.877285 49958 process.cpp:2494] Resuming (5485)@172.31.14.224:50909 at 2016-03-14 19:33:46.877277952+00:00
I0314 19:33:46.877385 49958 process.cpp:2599] Cleaning up (5485)@172.31.14.224:50909
I0314 19:33:46.877384 49950 process.cpp:2494] Resuming log-write(394)@172.31.14.224:50909 at 2016-03-14 19:33:46.877374976+00:00
I0314 19:33:46.877452 49952 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.877444096+00:00
I0314 19:33:46.877495 49960 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.877485056+00:00
I0314 19:33:46.877579 49960 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.877573120+00:00
I0314 19:33:46.877806 49950 process.cpp:2599] Cleaning up log-write(394)@172.31.14.224:50909
I0314 19:33:46.877825 49953 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.877816064+00:00
I0314 19:33:46.877879 49956 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.877869056+00:00
I0314 19:33:46.878057 49959 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.878049024+00:00
I0314 19:33:46.878135 49951 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.878126080+00:00
I0314 19:33:46.878140 49962 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.878130944+00:00
I0314 19:33:46.878250 49962 replica.cpp:691] Replica received learned notice for position 3 from @0.0.0.0:0
I0314 19:33:46.880347 49962 leveldb.cpp:341] Persisting action (461 bytes) to leveldb took 2.060139ms
I0314 19:33:46.880383 49962 replica.cpp:712] Persisted action at 3
I0314 19:33:46.880403 49962 replica.cpp:697] Replica learned APPEND action at position 3
I0314 19:33:46.880511 49955 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.880498944+00:00
I0314 19:33:46.880717 49956 process.cpp:2494] Resuming (5457)@172.31.14.224:50909 at 2016-03-14 19:33:46.880707072+00:00
I0314 19:33:46.881250 49949 process.cpp:2494] Resuming __latch__(1955)@172.31.14.224:50909 at 2016-03-14 19:33:46.881241088+00:00
I0314 19:33:46.881295 49949 process.cpp:2599] Cleaning up __latch__(1955)@172.31.14.224:50909
I0314 19:33:46.881352 49961 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.881342976+00:00
I0314 19:33:46.881412 49948 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.881401088+00:00
I0314 19:33:46.881489 49957 process.cpp:2494] Resuming registrar(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.881480960+00:00
I0314 19:33:46.881613 49957 registrar.cpp:484] Successfully updated the 'registry' in 6.53312ms
I0314 19:33:46.881778 49958 process.cpp:2494] Resuming log-writer(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.881766912+00:00
I0314 19:33:46.881786 49954 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:46.881775104+00:00
I0314 19:33:46.881839 49958 log.cpp:702] Attempting to truncate the log to 3
I0314 19:33:46.881913 49962 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.881902080+00:00
I0314 19:33:46.881966 49962 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 4
I0314 19:33:46.882107 49962 process.cpp:2484] Spawned process log-write(395)@172.31.14.224:50909
I0314 19:33:46.882135 49950 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.882125056+00:00
I0314 19:33:46.882145 49949 process.cpp:2494] Resuming log-write(395)@172.31.14.224:50909 at 2016-03-14 19:33:46.882136064+00:00
I0314 19:33:46.882144 49954 process.cpp:2484] Spawned process slave-observer(79)@172.31.14.224:50909
I0314 19:33:46.882154 49961 process.cpp:2494] Resuming slave-observer(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.882148096+00:00
I0314 19:33:46.882246 49958 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.882236928+00:00
I0314 19:33:46.882266 49953 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.882255104+00:00
I0314 19:33:46.882326 49953 slave.cpp:3482] Received ping from slave-observer(79)@172.31.14.224:50909
I0314 19:33:46.882359 49959 process.cpp:2494] Resuming (5455)@172.31.14.224:50909 at 2016-03-14 19:33:46.882348032+00:00
I0314 19:33:46.882414 49962 process.cpp:2494] Resuming log-write(395)@172.31.14.224:50909 at 2016-03-14 19:33:46.882405888+00:00
I0314 19:33:46.882452 49948 process.cpp:2494] Resuming slave-observer(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.882440960+00:00
I0314 19:33:46.882468 49953 slave.cpp:971] Registered with master master@172.31.14.224:50909; given slave ID dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0
I0314 19:33:46.882519 49953 fetcher.cpp:81] Clearing fetcher cache
I0314 19:33:46.882433 49954 master.cpp:4274] Registered slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0 at slave(79)@172.31.14.224:50909 (ip-172-31-14-224.us-west-1.compute.internal) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0314 19:33:46.882567 49947 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.882558976+00:00
I0314 19:33:46.882586 49954 process.cpp:2494] Resuming (5480)@172.31.14.224:50909 at 2016-03-14 19:33:46.882576896+00:00
I0314 19:33:46.882674 49959 hierarchical.cpp:473] Added slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0 (ip-172-31-14-224.us-west-1.compute.internal) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: )
I0314 19:33:46.882726 49954 status_update_manager.cpp:181] Resuming sending status updates
I0314 19:33:46.882688 49948 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.882681088+00:00
I0314 19:33:46.882802 49953 slave.cpp:994] Checkpointing SlaveInfo to '/tmp/MemoryPressureMesosTest_CGROUPS_ROOT_Statistics_rUXQlo/meta/slaves/dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0/slave.info'
I0314 19:33:46.882848 49947 process.cpp:2484] Spawned process (5486)@172.31.14.224:50909
I0314 19:33:46.882865 49961 process.cpp:2494] Resuming (5486)@172.31.14.224:50909 at 2016-03-14 19:33:46.882854912+00:00
I0314 19:33:46.882946 49954 process.cpp:2494] Resuming log-write(395)@172.31.14.224:50909 at 2016-03-14 19:33:46.882938112+00:00
I0314 19:33:46.882963 49949 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.882953984+00:00
I0314 19:33:46.883043 49949 replica.cpp:537] Replica received write request for position 4 from (5486)@172.31.14.224:50909
I0314 19:33:46.883060 49953 slave.cpp:1030] Forwarding total oversubscribed resources
I0314 19:33:46.883152 49959 hierarchical.cpp:1427] Allocating cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0 to framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:46.883163 49953 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:46.883154944+00:00
I0314 19:33:46.883280 49953 master.cpp:4618] Received update of slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0 at slave(79)@172.31.14.224:50909 (ip-172-31-14-224.us-west-1.compute.internal) with total oversubscribed resources
I0314 19:33:46.883548 49959 hierarchical.cpp:1548] No inverse offers to send out!
I0314 19:33:46.883544 49947 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:46.883535872+00:00
I0314 19:33:46.883605 49959 hierarchical.cpp:1150] Performed allocation for slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0 in 876646ns
I0314 19:33:46.883862 49947 master.cpp:5324] Sending 1 offers to framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 (default) at scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909
I0314 19:33:46.883877 49959 hierarchical.cpp:531] Slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0 (ip-172-31-14-224.us-west-1.compute.internal) updated with oversubscribed resources  (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000])
I0314 19:33:46.883975 49952 process.cpp:2494] Resuming scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909 at 2016-03-14 19:33:46.883965952+00:00
I0314 19:33:46.884016 49959 hierarchical.cpp:1453] No resources available to allocate!
I0314 19:33:46.884066 49959 hierarchical.cpp:1548] No inverse offers to send out!
I0314 19:33:46.884110 49952 pid.cpp:93] Attempting to parse 'master@172.31.14.224:50909' into a PID
I0314 19:33:46.884110 49959 hierarchical.cpp:1150] Performed allocation for slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0 in 180266ns
I0314 19:33:46.884155 49952 sched.cpp:849] Received 1 offers
I0314 19:33:46.884202 49952 pid.cpp:93] Attempting to parse 'slave(79)@172.31.14.224:50909' into a PID
I0314 19:33:46.884341 49952 sched.cpp:873] Scheduler::resourceOffers took 94515ns
I0314 19:33:46.884356 49947 process.cpp:2494] Resuming __latch__(1954)@172.31.14.224:50909 at 2016-03-14 19:33:46.884346880+00:00
I0314 19:33:46.884389 49947 process.cpp:2599] Cleaning up __latch__(1954)@172.31.14.224:50909
I0314 19:33:46.884459 49962 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.884449024+00:00
I0314 19:33:46.884503 49958 process.cpp:2494] Resuming __waiter__(806)@172.31.14.224:50909 at 2016-03-14 19:33:46.884494080+00:00
I0314 19:33:46.884541 49962 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.884531968+00:00
I0314 19:33:46.884582 49958 process.cpp:2599] Cleaning up __waiter__(806)@172.31.14.224:50909
I0314 19:33:46.884650 49961 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.884641024+00:00
I0314 19:33:46.884742 49933 resources.cpp:572] Parsing resources as JSON failed: cpus:1;mem:256;disk:1024
Trying semicolon-delimited string format instead
I0314 19:33:46.885025 49948 process.cpp:2494] Resuming scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909 at 2016-03-14 19:33:46.885017088+00:00
I0314 19:33:46.885066 49950 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.885057024+00:00
I0314 19:33:46.885084 49953 process.cpp:2494] Resuming __latch__(1956)@172.31.14.224:50909 at 2016-03-14 19:33:46.885074944+00:00
I0314 19:33:46.885087 49933 process.cpp:2484] Spawned process __latch__(1956)@172.31.14.224:50909
I0314 19:33:46.885188 49948 pid.cpp:93] Attempting to parse 'master@172.31.14.224:50909' into a PID
I0314 19:33:46.885216 49933 process.cpp:2484] Spawned process __waiter__(807)@172.31.14.224:50909
I0314 19:33:46.885238 49952 process.cpp:2494] Resuming __waiter__(807)@172.31.14.224:50909 at 2016-03-14 19:33:46.885227008+00:00
I0314 19:33:46.885277 49949 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 2.188949ms
I0314 19:33:46.885305 49949 replica.cpp:712] Persisted action at 4
I0314 19:33:46.885303 49955 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:46.885291008+00:00
I0314 19:33:46.885390 49960 process.cpp:2494] Resuming (5486)@172.31.14.224:50909 at 2016-03-14 19:33:46.885379072+00:00
I0314 19:33:46.885510 49947 process.cpp:2494] Resuming log-write(395)@172.31.14.224:50909 at 2016-03-14 19:33:46.885501952+00:00
I0314 19:33:46.885627 49960 process.cpp:2599] Cleaning up (5486)@172.31.14.224:50909
I0314 19:33:46.885673 49961 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.885662976+00:00
I0314 19:33:46.885710 49948 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.885700096+00:00
I0314 19:33:46.885741 49947 process.cpp:2599] Cleaning up log-write(395)@172.31.14.224:50909
I0314 19:33:46.885797 49953 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.885789952+00:00
I0314 19:33:46.885880 49953 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.885873920+00:00
I0314 19:33:46.885882 49948 process.cpp:2494] Resuming (5456)@172.31.14.224:50909 at 2016-03-14 19:33:46.885872128+00:00
I0314 19:33:46.885946 49955 master.cpp:3104] Processing ACCEPT call for offers: [ dbfcd71c-47c4-4b7a-bdff-6335751ecebe-O0 ] on slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0 at slave(79)@172.31.14.224:50909 (ip-172-31-14-224.us-west-1.compute.internal) for framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 (default) at scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909
I0314 19:33:46.886006 49955 master.cpp:2776] Authorizing framework principal 'test-principal' to launch task 2d338dad-d913-48f1-8ad5-82fb66715b44 as user 'root'
I0314 19:33:46.886013 49953 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.886004992+00:00
I0314 19:33:46.886162 49953 process.cpp:2494] Resuming log-replica(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.886155008+00:00
I0314 19:33:46.886183 49962 process.cpp:2494] Resuming authorizer(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.886174976+00:00
I0314 19:33:46.886215 49960 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.886205952+00:00
I0314 19:33:46.886234 49953 replica.cpp:691] Replica received learned notice for position 4 from @0.0.0.0:0
I0314 19:33:46.886410 49955 process.cpp:2484] Spawned process (5487)@172.31.14.224:50909
I0314 19:33:46.886430 49961 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.886418944+00:00
I0314 19:33:46.886440 49954 process.cpp:2494] Resuming (5487)@172.31.14.224:50909 at 2016-03-14 19:33:46.886430976+00:00
I0314 19:33:46.886560 49954 process.cpp:2599] Cleaning up (5487)@172.31.14.224:50909
I0314 19:33:46.886641 49948 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.886631936+00:00
I0314 19:33:46.886665 49952 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.886657024+00:00
I0314 19:33:46.886904 49953 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 628586ns
I0314 19:33:46.886963 49953 leveldb.cpp:399] Deleting ~2 keys from leveldb took 30533ns
I0314 19:33:46.886992 49953 replica.cpp:712] Persisted action at 4
I0314 19:33:46.887014 49953 replica.cpp:697] Replica learned TRUNCATE action at position 4
I0314 19:33:46.887112 49962 process.cpp:2494] Resuming log-coordinator(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.887105024+00:00
I0314 19:33:46.887292 49954 process.cpp:2494] Resuming (5457)@172.31.14.224:50909 at 2016-03-14 19:33:46.887283968+00:00
I0314 19:33:46.887295 49955 master.hpp:177] Adding task 2d338dad-d913-48f1-8ad5-82fb66715b44 with resources cpus(*):1; mem(*):256; disk(*):1024 on slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0 (ip-172-31-14-224.us-west-1.compute.internal)
I0314 19:33:46.887439 49955 master.cpp:3589] Launching task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 (default) at scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909 with resources cpus(*):1; mem(*):256; disk(*):1024 on slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0 at slave(79)@172.31.14.224:50909 (ip-172-31-14-224.us-west-1.compute.internal)
I0314 19:33:46.887616 49958 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.887606016+00:00
I0314 19:33:46.887671 49961 process.cpp:2494] Resuming (5455)@172.31.14.224:50909 at 2016-03-14 19:33:46.887661056+00:00
I0314 19:33:46.887732 49958 pid.cpp:93] Attempting to parse 'scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909' into a PID
I0314 19:33:46.887786 49958 slave.cpp:1361] Got assigned task 2d338dad-d913-48f1-8ad5-82fb66715b44 for framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:46.887909 49958 resources.cpp:572] Parsing resources as JSON failed: cpus:0.1;mem:32
Trying semicolon-delimited string format instead
I0314 19:33:46.887954 49961 hierarchical.cpp:890] Recovered cpus(*):1; mem(*):768; ports(*):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):1; mem(*):256; disk(*):1024) on slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0 from framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:46.888010 49961 hierarchical.cpp:927] Framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 filtered slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0 for 5secs
I0314 19:33:46.888245 49958 slave.cpp:1480] Launching task 2d338dad-d913-48f1-8ad5-82fb66715b44 for framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:46.888312 49958 resources.cpp:572] Parsing resources as JSON failed: cpus:0.1;mem:32
Trying semicolon-delimited string format instead
I0314 19:33:46.888664 49958 paths.cpp:528] Trying to chown '/tmp/MemoryPressureMesosTest_CGROUPS_ROOT_Statistics_rUXQlo/slaves/dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0/frameworks/dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000/executors/2d338dad-d913-48f1-8ad5-82fb66715b44/runs/c31eb40d-4df7-49d8-be9f-5173ef1410f6' to user 'root'
I0314 19:33:46.891252 49958 slave.cpp:5367] Launching executor 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 with resources cpus(*):0.1; mem(*):32 in work directory '/tmp/MemoryPressureMesosTest_CGROUPS_ROOT_Statistics_rUXQlo/slaves/dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0/frameworks/dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000/executors/2d338dad-d913-48f1-8ad5-82fb66715b44/runs/c31eb40d-4df7-49d8-be9f-5173ef1410f6'
I0314 19:33:46.891402 49956 process.cpp:2494] Resuming files@172.31.14.224:50909 at 2016-03-14 19:33:46.891373056+00:00
I0314 19:33:46.891535 49957 process.cpp:2494] Resuming (5478)@172.31.14.224:50909 at 2016-03-14 19:33:46.891504896+00:00
I0314 19:33:46.891616 49958 slave.cpp:1698] Queuing task '2d338dad-d913-48f1-8ad5-82fb66715b44' for executor '2d338dad-d913-48f1-8ad5-82fb66715b44' of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:46.891620 49957 containerizer.cpp:666] Starting container 'c31eb40d-4df7-49d8-be9f-5173ef1410f6' for executor '2d338dad-d913-48f1-8ad5-82fb66715b44' of framework 'dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000'
I0314 19:33:46.891721 49958 slave.cpp:749] Successfully attached file '/tmp/MemoryPressureMesosTest_CGROUPS_ROOT_Statistics_rUXQlo/slaves/dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0/frameworks/dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000/executors/2d338dad-d913-48f1-8ad5-82fb66715b44/runs/c31eb40d-4df7-49d8-be9f-5173ef1410f6'
I0314 19:33:46.891754 49957 process.cpp:2484] Spawned process (5488)@172.31.14.224:50909
I0314 19:33:46.891773 49955 process.cpp:2494] Resuming (5488)@172.31.14.224:50909 at 2016-03-14 19:33:46.891744000+00:00
I0314 19:33:46.892262 49958 process.cpp:2494] Resuming (5477)@172.31.14.224:50909 at 2016-03-14 19:33:46.892254976+00:00
I0314 19:33:46.892719 49951 process.cpp:2494] Resuming (5476)@172.31.14.224:50909 at 2016-03-14 19:33:46.892701952+00:00
I0314 19:33:46.900365 49951 process.cpp:2484] Spawned process (5489)@172.31.14.224:50909
I0314 19:33:46.900388 49949 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.900370944+00:00
I0314 19:33:46.900394 49956 process.cpp:2494] Resuming (5489)@172.31.14.224:50909 at 2016-03-14 19:33:46.900385024+00:00
I0314 19:33:46.900454 49951 mem.cpp:602] Started listening for OOM events for container c31eb40d-4df7-49d8-be9f-5173ef1410f6
I0314 19:33:46.901129 49951 process.cpp:2484] Spawned process (5490)@172.31.14.224:50909
I0314 19:33:46.901160 49962 process.cpp:2494] Resuming (5490)@172.31.14.224:50909 at 2016-03-14 19:33:46.901135872+00:00
I0314 19:33:46.901166 49951 mem.cpp:722] Started listening on low memory pressure events for container c31eb40d-4df7-49d8-be9f-5173ef1410f6
I0314 19:33:46.901224 49962 process.cpp:2484] Spawned process (5491)@172.31.14.224:50909
I0314 19:33:46.901262 49952 process.cpp:2494] Resuming (5491)@172.31.14.224:50909 at 2016-03-14 19:33:46.901242880+00:00
I0314 19:33:46.901842 49951 process.cpp:2484] Spawned process (5492)@172.31.14.224:50909
I0314 19:33:46.901864 49961 process.cpp:2494] Resuming (5492)@172.31.14.224:50909 at 2016-03-14 19:33:46.901850112+00:00
I0314 19:33:46.901887 49951 mem.cpp:722] Started listening on medium memory pressure events for container c31eb40d-4df7-49d8-be9f-5173ef1410f6
I0314 19:33:46.901933 49961 process.cpp:2484] Spawned process (5493)@172.31.14.224:50909
I0314 19:33:46.901950 49959 process.cpp:2494] Resuming (5493)@172.31.14.224:50909 at 2016-03-14 19:33:46.901934080+00:00
I0314 19:33:46.902546 49951 process.cpp:2484] Spawned process (5494)@172.31.14.224:50909
I0314 19:33:46.902570 49958 process.cpp:2494] Resuming (5494)@172.31.14.224:50909 at 2016-03-14 19:33:46.902558976+00:00
I0314 19:33:46.902585 49951 mem.cpp:722] Started listening on critical memory pressure events for container c31eb40d-4df7-49d8-be9f-5173ef1410f6
I0314 19:33:46.902628 49958 process.cpp:2484] Spawned process (5495)@172.31.14.224:50909
I0314 19:33:46.902647 49953 process.cpp:2494] Resuming (5495)@172.31.14.224:50909 at 2016-03-14 19:33:46.902626048+00:00
I0314 19:33:46.902971 49954 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.902957056+00:00
I0314 19:33:46.903354 49951 mem.cpp:353] Updated 'memory.soft_limit_in_bytes' to 288MB for container c31eb40d-4df7-49d8-be9f-5173ef1410f6
I0314 19:33:46.904392 49951 mem.cpp:388] Updated 'memory.limit_in_bytes' to 288MB for container c31eb40d-4df7-49d8-be9f-5173ef1410f6
I0314 19:33:46.904639 49962 process.cpp:2494] Resuming (5478)@172.31.14.224:50909 at 2016-03-14 19:33:46.904630016+00:00
I0314 19:33:46.904953 49948 process.cpp:2494] Resuming (5466)@172.31.14.224:50909 at 2016-03-14 19:33:46.904935936+00:00
I0314 19:33:46.905225 49961 process.cpp:2494] Resuming (5478)@172.31.14.224:50909 at 2016-03-14 19:33:46.905217024+00:00
I0314 19:33:46.906824 49961 linux_launcher.cpp:304] Cloning child process with flags =
I0314 19:33:46.907634 49952 process.cpp:2494] Resuming reaper(1)@172.31.14.224:50909 at 2016-03-14 19:33:46.907554048+00:00
I0314 19:33:46.908700 49958 process.cpp:2494] Resuming reaper(1)@172.31.14.224:50909 at 2016-03-14 19:33:46.908595968+00:00
I0314 19:33:46.908843 49958 process.cpp:2494] Resuming (5477)@172.31.14.224:50909 at 2016-03-14 19:33:46.908830976+00:00
I0314 19:33:46.908905 49959 process.cpp:2494] Resuming (5476)@172.31.14.224:50909 at 2016-03-14 19:33:46.908892928+00:00
I0314 19:33:46.908996 49958 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.908989952+00:00
I0314 19:33:46.909046 49961 process.cpp:2484] Spawned process (5496)@172.31.14.224:50909
I0314 19:33:46.909044 49962 process.cpp:2494] Resuming (5496)@172.31.14.224:50909 at 2016-03-14 19:33:46.909015040+00:00
I0314 19:33:46.909781 49959 process.cpp:2494] Resuming (5496)@172.31.14.224:50909 at 2016-03-14 19:33:46.909775104+00:00
I0314 19:33:46.909929 49962 process.cpp:2494] Resuming (5478)@172.31.14.224:50909 at 2016-03-14 19:33:46.909915904+00:00
I0314 19:33:46.909997 49959 process.cpp:2599] Cleaning up (5496)@172.31.14.224:50909
I0314 19:33:46.910106 49948 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.910087936+00:00
I0314 19:33:46.910171 49957 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.910140928+00:00
I0314 19:33:46.910249 49960 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:46.910228992+00:00
I0314 19:33:46.910409 49952 process.cpp:2494] Resuming (5478)@172.31.14.224:50909 at 2016-03-14 19:33:46.910400000+00:00
I0314 19:33:46.969312 49961 process.cpp:2494] Resuming reaper(1)@172.31.14.224:50909 at 2016-03-14 19:33:46.969289984+00:00
WARNING: Logging before InitGoogleLogging() is written to STDERR
I0314 19:33:46.997565 54411 process.cpp:2484] Spawned process __gc__@172.31.14.224:59163
I0314 19:33:46.997727 54425 process.cpp:2494] Resuming __gc__@172.31.14.224:59163 at 2016-03-14 19:33:46.997571072+00:00
I0314 19:33:46.997848 54411 process.cpp:2484] Spawned process help@172.31.14.224:59163
I0314 19:33:46.997879 54426 process.cpp:2494] Resuming __gc__@172.31.14.224:59163 at 2016-03-14 19:33:46.997851904+00:00
I0314 19:33:46.997905 54427 process.cpp:2494] Resuming help@172.31.14.224:59163 at 2016-03-14 19:33:46.997878016+00:00
I0314 19:33:46.997987 54411 process.cpp:2484] Spawned process logging@172.31.14.224:59163
I0314 19:33:46.998052 54434 process.cpp:2494] Resuming logging@172.31.14.224:59163 at 2016-03-14 19:33:46.997968896+00:00
I0314 19:33:46.998147 54411 process.cpp:2484] Spawned process profiler@172.31.14.224:59163
I0314 19:33:46.998172 54428 process.cpp:2494] Resuming profiler@172.31.14.224:59163 at 2016-03-14 19:33:46.998149120+00:00
I0314 19:33:46.998318 54438 process.cpp:2494] Resuming help@172.31.14.224:59163 at 2016-03-14 19:33:46.998189056+00:00
I0314 19:33:46.998420 54411 process.cpp:2484] Spawned process system@172.31.14.224:59163
I0314 19:33:46.998494 54433 process.cpp:2494] Resuming system@172.31.14.224:59163 at 2016-03-14 19:33:46.998432000+00:00
I0314 19:33:46.998642 54411 process.cpp:2484] Spawned process AuthenticationRouter(1)@172.31.14.224:59163
I0314 19:33:46.998651 54426 process.cpp:2494] Resuming AuthenticationRouter(1)@172.31.14.224:59163 at 2016-03-14 19:33:46.998642944+00:00
I0314 19:33:46.998663 54437 process.cpp:2494] Resuming metrics@172.31.14.224:59163 at 2016-03-14 19:33:46.998637056+00:00
I0314 19:33:46.998639 54433 process.cpp:2484] Spawned process metrics@172.31.14.224:59163
I0314 19:33:46.998855 54437 process.cpp:2494] Resuming help@172.31.14.224:59163 at 2016-03-14 19:33:46.998845952+00:00
I0314 19:33:46.998884 54438 process.cpp:2494] Resuming metrics@172.31.14.224:59163 at 2016-03-14 19:33:46.998875904+00:00
I0314 19:33:46.998992 54411 process.cpp:2484] Spawned process __processes__@172.31.14.224:59163
I0314 19:33:46.999032 54411 process.cpp:986] libprocess is initialized on 172.31.14.224:59163 for 16 cpus
I0314 19:33:46.999028 54429 process.cpp:2494] Resuming __processes__@172.31.14.224:59163 at 2016-03-14 19:33:46.999003904+00:00
I0314 19:33:46.999130 54411 process.cpp:2484] Spawned process (1)@172.31.14.224:59163
I0314 19:33:46.999125 54428 process.cpp:2494] Resuming (1)@172.31.14.224:59163 at 2016-03-14 19:33:46.999116032+00:00
I0314 19:33:46.999220 54431 process.cpp:2494] Resuming help@172.31.14.224:59163 at 2016-03-14 19:33:46.999086080+00:00
I0314 19:33:46.999519 54411 process.cpp:2484] Spawned process __latch__(1)@172.31.14.224:59163
I0314 19:33:46.999519 54438 process.cpp:2494] Resuming __gc__@172.31.14.224:59163 at 2016-03-14 19:33:46.999512064+00:00
I0314 19:33:46.999567 54411 logging.cpp:193] Logging to STDERR
I0314 19:33:46.999547 54430 process.cpp:2494] Resuming __latch__(1)@172.31.14.224:59163 at 2016-03-14 19:33:46.999525120+00:00
I0314 19:33:46.999632 54411 process.cpp:2484] Spawned process version@172.31.14.224:59163
I0314 19:33:46.999645 54429 process.cpp:2494] Resuming version@172.31.14.224:59163 at 2016-03-14 19:33:46.999635968+00:00
I0314 19:33:46.999722 54411 pid.cpp:93] Attempting to parse 'slave(79)@172.31.14.224:50909' into a PID
I0314 19:33:46.999788 54429 process.cpp:2494] Resuming help@172.31.14.224:59163 at 2016-03-14 19:33:46.999781888+00:00
I0314 19:33:47.001066 54411 exec.cpp:143] Version: 0.28.0
I0314 19:33:47.006434 54411 process.cpp:2484] Spawned process executor(1)@172.31.14.224:59163
I0314 19:33:47.006454 54434 process.cpp:2494] Resuming executor(1)@172.31.14.224:59163 at 2016-03-14 19:33:47.006446080+00:00
I0314 19:33:47.006489 54434 exec.cpp:193] Executor started at: executor(1)@172.31.14.224:59163 with pid 54411
I0314 19:33:47.007832 49963 pid.cpp:93] Attempting to parse 'executor(1)@172.31.14.224:59163' into a PID
I0314 19:33:47.007889 49963 process.cpp:612] Parsed message name 'mesos.internal.RegisterExecutorMessage' for slave(79)@172.31.14.224:50909 from executor(1)@172.31.14.224:59163
I0314 19:33:47.007983 49956 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.007962880+00:00
I0314 19:33:47.008035 49963 process.cpp:2484] Spawned process __http__(79)@172.31.14.224:50909
I0314 19:33:47.008056 49948 process.cpp:2494] Resuming __http__(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.008045056+00:00
I0314 19:33:47.008054 49951 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:47.008029952+00:00
I0314 19:33:47.008105 49956 slave.cpp:2643] Got registration for executor '2d338dad-d913-48f1-8ad5-82fb66715b44' of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 from executor(1)@172.31.14.224:59163
I0314 19:33:47.008169 49948 process.cpp:2484] Spawned process (5497)@172.31.14.224:50909
I0314 19:33:47.008203 49958 process.cpp:2494] Resuming (5497)@172.31.14.224:50909 at 2016-03-14 19:33:47.008189952+00:00
I0314 19:33:47.009093 49962 process.cpp:2494] Resuming (5478)@172.31.14.224:50909 at 2016-03-14 19:33:47.009079040+00:00
I0314 19:33:47.009176 54441 pid.cpp:93] Attempting to parse 'slave(79)@172.31.14.224:50909' into a PID
I0314 19:33:47.009238 54441 process.cpp:612] Parsed message name 'mesos.internal.ExecutorRegisteredMessage' for executor(1)@172.31.14.224:59163 from slave(79)@172.31.14.224:50909
I0314 19:33:47.009265 49953 process.cpp:2494] Resuming (5477)@172.31.14.224:50909 at 2016-03-14 19:33:47.009251072+00:00
II0314 19:33:47.009356 49949 process.cpp:2494] Resuming (5476)@172.31.14.224:50909 at 2016-03-14 19:33:47.009337088+00:00
0314 19:33:47.009373 54435 process.cpp:2494] Resuming executor(1)@172.31.14.224:59163 at 2016-03-14 19:33:47.009344000+00:00
I0314 19:33:47.009418 49960 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:47.009406976+00:00
I0314 19:33:47.009431 49962 process.cpp:2484] Spawned process (5498)@172.31.14.224:50909
I0314 19:33:47.009449 49957 process.cpp:2494] Resuming (5498)@172.31.14.224:50909 at 2016-03-14 19:33:47.009436928+00:00
I0314 19:33:47.009506 54441 process.cpp:2484] Spawned process __http__(1)@172.31.14.224:59163
I0314 19:33:47.009510 54430 process.cpp:2494] Resuming __http__(1)@172.31.14.224:59163 at 2016-03-14 19:33:47.009499904+00:00
I0314 19:33:47.009565 54436 process.cpp:2494] Resuming __gc__@172.31.14.224:59163 at 2016-03-14 19:33:47.009486080+00:00
I0314 19:33:47.009665 54430 process.cpp:2484] Spawned process (2)@172.31.14.224:59163
I0314 19:33:47.009749 54435 exec.cpp:217] Executor registered on slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0
I0314 19:33:47.009831 54432 process.cpp:2494] Resuming (2)@172.31.14.224:59163 at 2016-03-14 19:33:47.009807872+00:00
I0314 19:33:47.010257 49949 mem.cpp:353] Updated 'memory.soft_limit_in_bytes' to 288MB for container c31eb40d-4df7-49d8-be9f-5173ef1410f6
I0314 19:33:47.010890 49956 process.cpp:2494] Resuming (5498)@172.31.14.224:50909 at 2016-03-14 19:33:47.010875904+00:00
I0314 19:33:47.011078 49954 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.011060992+00:00
I0314 19:33:47.011152 49956 process.cpp:2599] Cleaning up (5498)@172.31.14.224:50909
I0314 19:33:47.011168 54435 exec.cpp:229] Executor::registered took 230156ns
I0314 19:33:47.011183 54428 process.cpp:2494] Resuming (1)@172.31.14.224:59163 at 2016-03-14 19:33:47.011156992+00:00
I0314 19:33:47.011239 49957 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:47.011226880+00:00
I0314 19:33:47.011258 49954 slave.cpp:1863] Sending queued task '2d338dad-d913-48f1-8ad5-82fb66715b44' to executor '2d338dad-d913-48f1-8ad5-82fb66715b44' of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 at executor(1)@172.31.14.224:59163
Registered executor on ip-172-31-14-224.us-west-1.compute.internal
I0314 19:33:47.011315 49960 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:47.011307008+00:00
I0314 19:33:47.011745 54441 pid.cpp:93] Attempting to parse 'slave(79)@172.31.14.224:50909' into a PID
I0314 19:33:47.011792 54441 process.cpp:612] Parsed message name 'mesos.internal.RunTaskMessage' for executor(1)@172.31.14.224:59163 from slave(79)@172.31.14.224:50909
I0314 19:33:47.011869 54436 process.cpp:2494] Resuming executor(1)@172.31.14.224:59163 at 2016-03-14 19:33:47.011860992+00:00
I0314 19:33:47.012091 54436 exec.cpp:304] Executor asked to run task '2d338dad-d913-48f1-8ad5-82fb66715b44'
I0314 19:33:47.012198 54436 exec.cpp:313] Executor::launchTask took 70033ns
I0314 19:33:47.012207 54438 process.cpp:2494] Resuming (1)@172.31.14.224:59163 at 2016-03-14 19:33:47.012198912+00:00
Starting task 2d338dad-d913-48f1-8ad5-82fb66715b44
Forked command at 54442
sh -c 'while true; do dd count=512 bs=1M if=/dev/zero of=./temp; done'
I0314 19:33:47.013175 54438 process.cpp:2484] Spawned process reaper(1)@172.31.14.224:59163
I0314 19:33:47.013203 54430 process.cpp:2494] Resuming reaper(1)@172.31.14.224:59163 at 2016-03-14 19:33:47.013192960+00:00
I0314 19:33:47.013514 54431 process.cpp:2494] Resuming executor(1)@172.31.14.224:59163 at 2016-03-14 19:33:47.013502976+00:00
I0314 19:33:47.014701 54431 exec.cpp:526] Executor sending status update TASK_RUNNING (UUID: a9675e8c-e6f3-45a4-ad5b-50bf49938661) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.015219 49963 pid.cpp:93] Attempting to parse 'executor(1)@172.31.14.224:59163' into a PID
I0314 19:33:47.015281 49963 process.cpp:612] Parsed message name 'mesos.internal.StatusUpdateMessage' for slave(79)@172.31.14.224:50909 from executor(1)@172.31.14.224:59163
I0314 19:33:47.015395 49947 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.015363072+00:00
I0314 19:33:47.015506 49947 pid.cpp:93] Attempting to parse 'executor(1)@172.31.14.224:59163' into a PID
I0314 19:33:47.015578 49947 slave.cpp:3002] Handling status update TASK_RUNNING (UUID: a9675e8c-e6f3-45a4-ad5b-50bf49938661) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 from executor(1)@172.31.14.224:59163
I0314 19:33:47.015820 49948 process.cpp:2494] Resuming (5478)@172.31.14.224:50909 at 2016-03-14 19:33:47.015811072+00:00
I0314 19:33:47.015924 49951 process.cpp:2494] Resuming (5477)@172.31.14.224:50909 at 2016-03-14 19:33:47.015916032+00:00
I0314 19:33:47.015964 49948 containerizer.cpp:1367] Serializing status request for container: c31eb40d-4df7-49d8-be9f-5173ef1410f6
I0314 19:33:47.015966 49952 process.cpp:2494] Resuming (5476)@172.31.14.224:50909 at 2016-03-14 19:33:47.015956992+00:00
I0314 19:33:47.016039 49957 process.cpp:2494] Resuming (5488)@172.31.14.224:50909 at 2016-03-14 19:33:47.016028928+00:00
I0314 19:33:47.016228 49957 process.cpp:2484] Spawned process (5499)@172.31.14.224:50909
I0314 19:33:47.016243 49951 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:47.016236032+00:00
I0314 19:33:47.016270 49958 process.cpp:2494] Resuming (5499)@172.31.14.224:50909 at 2016-03-14 19:33:47.016260096+00:00
I0314 19:33:47.016490 49958 containerizer.cpp:1344] Aggregating status for container: c31eb40d-4df7-49d8-be9f-5173ef1410f6
I0314 19:33:47.016660 49950 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.016641024+00:00
I0314 19:33:47.016685 49958 process.cpp:2599] Cleaning up (5499)@172.31.14.224:50909
I0314 19:33:47.016752 49961 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:47.016741888+00:00
I0314 19:33:47.016793 49955 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:47.016775936+00:00
I0314 19:33:47.016978 49959 process.cpp:2494] Resuming (5480)@172.31.14.224:50909 at 2016-03-14 19:33:47.016966912+00:00
I0314 19:33:47.017026 49959 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: a9675e8c-e6f3-45a4-ad5b-50bf49938661) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.017068 49959 status_update_manager.cpp:497] Creating StatusUpdate stream for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.017396 49959 status_update_manager.cpp:374] Forwarding update TASK_RUNNING (UUID: a9675e8c-e6f3-45a4-ad5b-50bf49938661) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 to the slave
I0314 19:33:47.017556 49956 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.017545984+00:00
I0314 19:33:47.017659 49956 slave.cpp:3400] Forwarding the update TASK_RUNNING (UUID: a9675e8c-e6f3-45a4-ad5b-50bf49938661) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 to master@172.31.14.224:50909
I0314 19:33:47.017814 49957 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:47.017804032+00:00
I0314 19:33:47.017832 49956 slave.cpp:3294] Status update manager successfully handled status update TASK_RUNNING (UUID: a9675e8c-e6f3-45a4-ad5b-50bf49938661) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.017875 49956 slave.cpp:3310] Sending acknowledgement for status update TASK_RUNNING (UUID: a9675e8c-e6f3-45a4-ad5b-50bf49938661) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 to executor(1)@172.31.14.224:59163
I0314 19:33:47.017922 49957 pid.cpp:93] Attempting to parse 'slave(79)@172.31.14.224:50909' into a PID
I0314 19:33:47.018012 49957 master.cpp:4763] Status update TASK_RUNNING (UUID: a9675e8c-e6f3-45a4-ad5b-50bf49938661) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 from slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0 at slave(79)@172.31.14.224:50909 (ip-172-31-14-224.us-west-1.compute.internal)
I0314 19:33:47.018059 49957 master.cpp:4811] Forwarding status update TASK_RUNNING (UUID: a9675e8c-e6f3-45a4-ad5b-50bf49938661) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.018165 54441 pid.cpp:93] Attempting to parse 'slave(79)@172.31.14.224:50909' into a PID
I0314 19:33:47.018177 49952 process.cpp:2494] Resuming scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909 at 2016-03-14 19:33:47.018169088+00:00
I0314 19:33:47.018200 49957 master.cpp:6421] Updating the state of task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I0314 19:33:47.018226 54441 process.cpp:612] Parsed message name 'mesos.internal.StatusUpdateAcknowledgementMessage' for executor(1)@172.31.14.224:59163 from slave(79)@172.31.14.224:50909
I0314 19:33:47.018281 49952 pid.cpp:93] Attempting to parse 'slave(79)@172.31.14.224:50909' into a PID
I0314 19:33:47.018302 54426 process.cpp:2494] Resuming executor(1)@172.31.14.224:59163 at 2016-03-14 19:33:47.018291968+00:00
I0314 19:33:47.018326 49952 pid.cpp:93] Attempting to parse 'master@172.31.14.224:50909' into a PID
I0314 19:33:47.018347 49952 sched.cpp:942] Received status update TASK_RUNNING (UUID: a9675e8c-e6f3-45a4-ad5b-50bf49938661) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 from slave(79)@172.31.14.224:50909
I0314 19:33:47.018400 54426 exec.cpp:350] Executor received status update acknowledgement a9675e8c-e6f3-45a4-ad5b-50bf49938661 for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.018519 49952 sched.cpp:981] Scheduler::statusUpdate took 106976ns
I0314 19:33:47.018543 49950 process.cpp:2494] Resuming __latch__(1956)@172.31.14.224:50909 at 2016-03-14 19:33:47.018530048+00:00
I0314 19:33:47.018550 49952 sched.cpp:1000] Sending ACK for status update TASK_RUNNING (UUID: a9675e8c-e6f3-45a4-ad5b-50bf49938661) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 to master@172.31.14.224:50909
I0314 19:33:47.018580 49950 process.cpp:2599] Cleaning up __latch__(1956)@172.31.14.224:50909
I0314 19:33:47.018612 49952 pid.cpp:93] Attempting to parse 'master@172.31.14.224:50909' into a PID
I0314 19:33:47.018676 49958 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:47.018667008+00:00
I0314 19:33:47.018702 49947 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:47.018691072+00:00
I0314 19:33:47.018745 49956 process.cpp:2494] Resuming __waiter__(807)@172.31.14.224:50909 at 2016-03-14 19:33:47.018734080+00:00
I0314 19:33:47.018821 49947 master.cpp:3918] Processing ACKNOWLEDGE call a9675e8c-e6f3-45a4-ad5b-50bf49938661 for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 (default) at scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909 on slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0
I0314 19:33:47.018959 49955 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:47.018949120+00:00
I0314 19:33:47.019037 49956 process.cpp:2599] Cleaning up __waiter__(807)@172.31.14.224:50909
I0314 19:33:47.019047 49955 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.019041024+00:00
I0314 19:33:47.019124 49948 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:47.019113984+00:00
I0314 19:33:47.019307 49954 process.cpp:2494] Resuming (5480)@172.31.14.224:50909 at 2016-03-14 19:33:47.019297024+00:00
I0314 19:33:47.019330 49951 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:47.019320064+00:00
I0314 19:33:47.019304 49949 process.cpp:2494] Resuming (5478)@172.31.14.224:50909 at 2016-03-14 19:33:47.019293952+00:00
I0314 19:33:47.019376 49954 status_update_manager.cpp:392] Received status update acknowledgement (UUID: a9675e8c-e6f3-45a4-ad5b-50bf49938661) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.019371 49961 process.cpp:2494] Resuming __latch__(1957)@172.31.14.224:50909 at 2016-03-14 19:33:47.019363072+00:00
I0314 19:33:47.019642 49960 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.019630080+00:00
I0314 19:33:47.019364 49933 process.cpp:2484] Spawned process __latch__(1957)@172.31.14.224:50909
I0314 19:33:47.019717 49960 slave.cpp:2412] Status update manager successfully handled status update acknowledgement (UUID: a9675e8c-e6f3-45a4-ad5b-50bf49938661) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.019807 49954 process.cpp:2494] Resuming __latch__(1957)@172.31.14.224:50909 at 2016-03-14 19:33:47.019761920+00:00
I0314 19:33:47.019809 49949 process.cpp:2494] Resuming (5478)@172.31.14.224:50909 at 2016-03-14 19:33:47.019801088+00:00
...
....
...
I0314 19:33:47.333453 49959 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:47.333444096+00:00
I0314 19:33:47.333483 49955 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:47.333474048+00:00
I0314 19:33:47.333602 49955 process.cpp:2494] Resuming __waiter__(811)@172.31.14.224:50909 at 2016-03-14 19:33:47.333595904+00:00
I0314 19:33:47.333659 49955 process.cpp:2599] Cleaning up __waiter__(811)@172.31.14.224:50909
I0314 19:33:47.333724 49949 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:47.333715968+00:00
I0314 19:33:47.333797 49933 clock.cpp:331] Clock paused at 0x3e84f40
I0314 19:33:47.344027 49957 process.cpp:2494] Resuming scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.344110 49957 pid.cpp:93] Attempting to parse 'master@172.31.14.224:50909' into a PID
I0314 19:33:47.344218 49953 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.344411 49953 master.cpp:3826] Telling slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0 at slave(79)@172.31.14.224:50909 (ip-172-31-14-224.us-west-1.compute.internal) to kill task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 (default) at scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909
I0314 19:33:47.344516 49961 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.344602 49961 slave.cpp:1891] Asked to kill task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.345041 54441 pid.cpp:93] Attempting to parse 'slave(79)@172.31.14.224:50909' into a PID
I0314 19:33:47.345093 54441 process.cpp:612] Parsed message name 'mesos.internal.KillTaskMessage' for executor(1)@172.31.14.224:59163 from slave(79)@172.31.14.224:50909
I0314 19:33:47.345180 54436 process.cpp:2494] Resuming executor(1)@172.31.14.224:59163 at 2016-03-14 19:33:47.345161984+00:00
I0314 19:33:47.345288 54436 exec.cpp:324] Executor asked to kill task '2d338dad-d913-48f1-8ad5-82fb66715b44'
I0314 19:33:47.345358 54436 exec.cpp:333] Executor::killTask took 40465ns
I0314 19:33:47.345376 54425 process.cpp:2494] Resuming (1)@172.31.14.224:59163 at 2016-03-14 19:33:47.345362944+00:00
Received killTask
Shutting down
Sending SIGTERM to process tree at pid 54442
Sent SIGTERM to the following process trees:
[
-+- 54442 sh -c while true; do dd count=512 bs=1M if=/dev/zero of=./temp; done
 \--- 54443 dd count=512 bs=1M if=/dev/zero of=./temp
]
I0314 19:33:47.416590 54433 process.cpp:2494] Resuming reaper(1)@172.31.14.224:59163 at 2016-03-14 19:33:47.416573952+00:00
I0314 19:33:47.416932 54440 process.cpp:2494] Resuming (1)@172.31.14.224:59163 at 2016-03-14 19:33:47.416908032+00:00
Command terminated with signal Terminated (pid: 54442)
I0314 19:33:47.417114 54435 process.cpp:2494] Resuming executor(1)@172.31.14.224:59163 at 2016-03-14 19:33:47.417103872+00:00
I0314 19:33:47.417201 54435 exec.cpp:526] Executor sending status update TASK_KILLED (UUID: bdeb417f-be4d-4577-98cf-c1ab7639269d) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.417579 49963 pid.cpp:93] Attempting to parse 'executor(1)@172.31.14.224:59163' into a PID
I0314 19:33:47.417623 49963 process.cpp:612] Parsed message name 'mesos.internal.StatusUpdateMessage' for slave(79)@172.31.14.224:50909 from executor(1)@172.31.14.224:59163
I0314 19:33:47.417700 49953 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.417794 49953 pid.cpp:93] Attempting to parse 'executor(1)@172.31.14.224:59163' into a PID
I0314 19:33:47.417852 49953 slave.cpp:3002] Handling status update TASK_KILLED (UUID: bdeb417f-be4d-4577-98cf-c1ab7639269d) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 from executor(1)@172.31.14.224:59163
I0314 19:33:47.418040 49957 process.cpp:2494] Resuming (5478)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.418165 49958 process.cpp:2494] Resuming (5477)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.418192 49957 containerizer.cpp:1367] Serializing status request for container: c31eb40d-4df7-49d8-be9f-5173ef1410f6
I0314 19:33:47.418187 49962 process.cpp:2494] Resuming (5476)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.418277 49947 process.cpp:2494] Resuming (5488)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.418480 49947 clock.cpp:435] Clock of (5508)@172.31.14.224:50909 updated to 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.418573 49947 process.cpp:2484] Spawned process (5508)@172.31.14.224:50909
I0314 19:33:47.418591 49952 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.418603 49950 process.cpp:2494] Resuming (5508)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.418789 49950 containerizer.cpp:1344] Aggregating status for container: c31eb40d-4df7-49d8-be9f-5173ef1410f6
I0314 19:33:47.418949 49953 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.419003 49950 process.cpp:2599] Cleaning up (5508)@172.31.14.224:50909
I0314 19:33:47.419073 49953 slave.cpp:5677] Terminating task 2d338dad-d913-48f1-8ad5-82fb66715b44
I0314 19:33:47.419106 49958 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.419131 49954 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.419329 49954 process.cpp:2494] Resuming (5478)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.419476 49957 process.cpp:2494] Resuming (5477)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.419577 49960 process.cpp:2494] Resuming (5476)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.419649 49954 clock.cpp:435] Clock of (5509)@172.31.14.224:50909 updated to 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.419724 49954 process.cpp:2484] Spawned process (5509)@172.31.14.224:50909
I0314 19:33:47.419741 49959 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.419769 49952 process.cpp:2494] Resuming (5509)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.420367 49960 mem.cpp:353] Updated 'memory.soft_limit_in_bytes' to 32MB for container c31eb40d-4df7-49d8-be9f-5173ef1410f6
I0314 19:33:47.420971 49960 process.cpp:2494] Resuming (5509)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.421181 49957 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.421205 49960 process.cpp:2599] Cleaning up (5509)@172.31.14.224:50909
I0314 19:33:47.421304 49961 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.421330 49948 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.421381 49961 process.cpp:2494] Resuming (5480)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.421437 49961 status_update_manager.cpp:320] Received status update TASK_KILLED (UUID: bdeb417f-be4d-4577-98cf-c1ab7639269d) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.421602 49961 status_update_manager.cpp:374] Forwarding update TASK_KILLED (UUID: bdeb417f-be4d-4577-98cf-c1ab7639269d) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 to the slave
I0314 19:33:47.421777 49954 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.421869 49954 slave.cpp:3400] Forwarding the update TASK_KILLED (UUID: bdeb417f-be4d-4577-98cf-c1ab7639269d) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 to master@172.31.14.224:50909
I0314 19:33:47.422022 49948 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.422034 49954 slave.cpp:3294] Status update manager successfully handled status update TASK_KILLED (UUID: bdeb417f-be4d-4577-98cf-c1ab7639269d) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.422096 49954 slave.cpp:3310] Sending acknowledgement for status update TASK_KILLED (UUID: bdeb417f-be4d-4577-98cf-c1ab7639269d) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 to executor(1)@172.31.14.224:59163
I0314 19:33:47.422142 49948 pid.cpp:93] Attempting to parse 'slave(79)@172.31.14.224:50909' into a PID
I0314 19:33:47.422211 49948 master.cpp:4763] Status update TASK_KILLED (UUID: bdeb417f-be4d-4577-98cf-c1ab7639269d) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 from slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0 at slave(79)@172.31.14.224:50909 (ip-172-31-14-224.us-west-1.compute.internal)
I0314 19:33:47.422255 49948 master.cpp:4811] Forwarding status update TASK_KILLED (UUID: bdeb417f-be4d-4577-98cf-c1ab7639269d) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.422389 49947 process.cpp:2494] Resuming scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.422396 54441 pid.cpp:93] Attempting to parse 'slave(79)@172.31.14.224:50909' into a PID
I0314 19:33:47.422399 49948 master.cpp:6421] Updating the state of task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
I0314 19:33:47.422479 54441 process.cpp:612] Parsed message name 'mesos.internal.StatusUpdateAcknowledgementMessage' for executor(1)@172.31.14.224:59163 from slave(79)@172.31.14.224:50909
I0314 19:33:47.422528 49947 pid.cpp:93] Attempting to parse 'slave(79)@172.31.14.224:50909' into a PID
I0314 19:33:47.422562 49957 process.cpp:2494] Resuming (5455)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.422587 54425 process.cpp:2494] Resuming executor(1)@172.31.14.224:59163 at 2016-03-14 19:33:47.422571008+00:00
I0314 19:33:47.422581 49947 pid.cpp:93] Attempting to parse 'master@172.31.14.224:50909' into a PID
I0314 19:33:47.422653 54425 exec.cpp:350] Executor received status update acknowledgement bdeb417f-be4d-4577-98cf-c1ab7639269d for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.422652 49947 sched.cpp:942] Received status update TASK_KILLED (UUID: bdeb417f-be4d-4577-98cf-c1ab7639269d) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 from slave(79)@172.31.14.224:50909
I0314 19:33:47.422812 49947 sched.cpp:981] Scheduler::statusUpdate took 83855ns
I0314 19:33:47.422843 49947 sched.cpp:1000] Sending ACK for status update TASK_KILLED (UUID: bdeb417f-be4d-4577-98cf-c1ab7639269d) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 to master@172.31.14.224:50909
I0314 19:33:47.422885 49947 pid.cpp:93] Attempting to parse 'master@172.31.14.224:50909' into a PID
I0314 19:33:47.422914 49957 hierarchical.cpp:890] Recovered cpus(*):1; mem(*):256; disk(*):1024 (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: ) on slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0 from framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.422971 49947 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.423082 49947 master.cpp:3918] Processing ACKNOWLEDGE call bdeb417f-be4d-4577-98cf-c1ab7639269d for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 (default) at scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909 on slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0
I0314 19:33:47.423141 49947 master.cpp:6487] Removing task 2d338dad-d913-48f1-8ad5-82fb66715b44 with resources cpus(*):1; mem(*):256; disk(*):1024 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 on slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0 at slave(79)@172.31.14.224:50909 (ip-172-31-14-224.us-west-1.compute.internal)
I0314 19:33:47.423351 49962 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.423498 49947 process.cpp:2494] Resuming (5480)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.423547 49947 status_update_manager.cpp:392] Received status update acknowledgement (UUID: bdeb417f-be4d-4577-98cf-c1ab7639269d) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.423665 49947 status_update_manager.cpp:528] Cleaning up status update stream for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.423915 49952 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.423964 49952 slave.cpp:2412] Status update manager successfully handled status update acknowledgement (UUID: bdeb417f-be4d-4577-98cf-c1ab7639269d) for task 2d338dad-d913-48f1-8ad5-82fb66715b44 of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.424008 49952 slave.cpp:5718] Completing task 2d338dad-d913-48f1-8ad5-82fb66715b44
I0314 19:33:47.425010 49948 process.cpp:2494] Resuming (5478)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.425137 49947 process.cpp:2494] Resuming (5477)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.425163 49961 process.cpp:2494] Resuming (5476)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.425214 49948 clock.cpp:435] Clock of (5510)@172.31.14.224:50909 updated to 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.425292 49948 process.cpp:2484] Spawned process (5510)@172.31.14.224:50909
I0314 19:33:47.425300 49951 process.cpp:2494] Resuming (5510)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.425386 49956 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.426619 49962 process.cpp:2494] Resuming (5494)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.426664 49959 process.cpp:2494] Resuming (5492)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.426702 49950 process.cpp:2494] Resuming (5490)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.426806 49961 clock.cpp:435] Clock of (5511)@172.31.14.224:50909 updated to 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.426909 49961 process.cpp:2484] Spawned process (5511)@172.31.14.224:50909
I0314 19:33:47.426906 49954 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.426923 49953 process.cpp:2494] Resuming (5511)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.427196 49960 process.cpp:2494] Resuming (5476)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.427284 49953 process.cpp:2599] Cleaning up (5511)@172.31.14.224:50909
I0314 19:33:47.427369 49954 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.427409 49948 process.cpp:2494] Resuming (5510)@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.427467 49955 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.427626 49948 process.cpp:2599] Cleaning up (5510)@172.31.14.224:50909
I0314 19:33:47.427723 49957 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.427753 49962 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:47.333786880+00:00
I0314 19:33:47.435119 49933 clock.cpp:361] Clock resumed at 0x3e6dce0
I0314 19:33:47.435175 49933 sched.cpp:1903] Asked to stop the driver
I0314 19:33:47.435263 49960 process.cpp:2494] Resuming scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909 at 2016-03-14 19:33:47.435254016+00:00
I0314 19:33:47.435267 49958 process.cpp:2494] Resuming reaper(1)@172.31.14.224:50909 at 2016-03-14 19:33:47.435258880+00:00
I0314 19:33:47.435325 49960 sched.cpp:1143] Stopping framework 'dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000'
I0314 19:33:47.435375 49960 pid.cpp:93] Attempting to parse 'master@172.31.14.224:50909' into a PID
I0314 19:33:47.435444 49956 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:47.435435008+00:00
I0314 19:33:47.435559 49948 process.cpp:2494] Resuming __latch__(1953)@172.31.14.224:50909 at 2016-03-14 19:33:47.435549952+00:00
I0314 19:33:47.435571 49960 process.cpp:2599] Cleaning up scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909
I0314 19:33:47.435607 49956 master.cpp:5897] Processing TEARDOWN call for framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 (default) at scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909
I0314 19:33:47.435600 49948 process.cpp:2599] Cleaning up __latch__(1953)@172.31.14.224:50909
I0314 19:33:47.435663 49962 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:47.435653888+00:00
I0314 19:33:47.435650 49956 master.cpp:5909] Removing framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 (default) at scheduler-dd4dfebb-e14f-4a77-adef-b9fc081c293e@172.31.14.224:50909
I0314 19:33:47.435807 49950 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:47.435800064+00:00
I0314 19:33:47.435820 49960 process.cpp:2494] Resuming (5455)@172.31.14.224:50909 at 2016-03-14 19:33:47.435811072+00:00
I0314 19:33:47.435865 49957 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:47.435856896+00:00
I0314 19:33:47.435897 49960 hierarchical.cpp:375] Deactivated framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.435968 49957 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.435961088+00:00
I0314 19:33:47.435974 49962 process.cpp:2494] Resuming AuthenticationRouter(1)@172.31.14.224:50909 at 2016-03-14 19:33:47.435965952+00:00
I0314 19:33:47.436100 49949 process.cpp:2494] Resuming (5459)@172.31.14.224:50909 at 2016-03-14 19:33:47.436091904+00:00
I0314 19:33:47.436116 49957 slave.cpp:2079] Asked to shut down framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 by master@172.31.14.224:50909
I0314 19:33:47.436184 49957 slave.cpp:2104] Shutting down framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.436188 49949 process.cpp:2599] Cleaning up (5459)@172.31.14.224:50909
I0314 19:33:47.436259 49957 slave.cpp:4198] Shutting down executor '2d338dad-d913-48f1-8ad5-82fb66715b44' of framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000 at executor(1)@172.31.14.224:59163
I0314 19:33:47.436285 49952 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:47.436275968+00:00
I0314 19:33:47.436295 49960 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:47.436286976+00:00
I0314 19:33:47.436310 49948 process.cpp:2494] Resuming (5455)@172.31.14.224:50909 at 2016-03-14 19:33:47.436300032+00:00
I0314 19:33:47.436316 49956 master.cpp:1026] Master terminating
I0314 19:33:47.436511 49948 hierarchical.cpp:326] Removed framework dbfcd71c-47c4-4b7a-bdff-6335751ecebe-0000
I0314 19:33:47.436528 54441 pid.cpp:93] Attempting to parse 'slave(79)@172.31.14.224:50909' into a PID
I0314 19:33:47.436522 49957 process.cpp:2494] Resuming slave-observer(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.436514048+00:00
I0314 19:33:47.436566 54441 process.cpp:612] Parsed message name 'mesos.internal.ShutdownExecutorMessage' for executor(1)@172.31.14.224:59163 from slave(79)@172.31.14.224:50909
I0314 19:33:47.436574 49957 process.cpp:2599] Cleaning up slave-observer(79)@172.31.14.224:50909
II0314 19:33:47.436636 49959 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:47.436626944+00:00
0314 19:33:47.436636 54433 process.cpp:2494] Resuming executor(1)@172.31.14.224:59163 at 2016-03-14 19:33:47.436627968+00:00
I0314 19:33:47.436718 54433 exec.cpp:390] Executor asked to shutdown
I0314 19:33:47.436826 49948 hierarchical.cpp:505] Removed slave dbfcd71c-47c4-4b7a-bdff-6335751ecebe-S0
I0314 19:33:47.436823 54438 process.cpp:2494] Resuming __gc__@172.31.14.224:59163 at 2016-03-14 19:33:47.436813056+00:00
I0314 19:33:47.436823 54433 process.cpp:2484] Spawned process (3)@172.31.14.224:59163
I0314 19:33:47.436868 49961 process.cpp:2494] Resuming whitelist(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.436854016+00:00
I0314 19:33:47.436843 54436 process.cpp:2494] Resuming (3)@172.31.14.224:59163 at 2016-03-14 19:33:47.436834048+00:00
I0314 19:33:47.436910 49961 process.cpp:2599] Cleaning up whitelist(79)@172.31.14.224:50909
I0314 19:33:47.436920 54433 exec.cpp:405] Executor::shutdown took 15256ns
I0314 19:33:47.436926 54436 exec.cpp:87] Scheduling shutdown of the executor in 5secs
I0314 19:33:47.436977 49960 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:47.436966912+00:00
I0314 19:33:47.437053 49951 process.cpp:2494] Resuming crammd5_authenticator(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.437046016+00:00
I0314 19:33:47.437094 49951 process.cpp:2599] Cleaning up crammd5_authenticator(79)@172.31.14.224:50909
I0314 19:33:47.437157 49952 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:47.437148928+00:00
I0314 19:33:47.437216 49956 process.cpp:2599] Cleaning up master@172.31.14.224:50909
I0314 19:33:47.437319 49950 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:47.437312000+00:00
I0314 19:33:47.437393 49949 process.cpp:2494] Resuming slave(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.437380096+00:00
I0314 19:33:47.437445 49949 slave.cpp:3528] master@172.31.14.224:50909 exited
W0314 19:33:47.437471 49949 slave.cpp:3531] Master disconnected! Waiting for a new master to be elected
I0314 19:33:47.437470 49954 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:47.437458944+00:00
I0314 19:33:47.438294 49958 process.cpp:2494] Resuming (5455)@172.31.14.224:50909 at 2016-03-14 19:33:47.438283008+00:00
I0314 19:33:47.438347 49958 process.cpp:2599] Cleaning up (5455)@172.31.14.224:50909
I0314 19:33:47.438423 49962 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:47.438415104+00:00
I0314 19:33:47.438526 49961 process.cpp:2494] Resuming authorizer(79)@172.31.14.224:50909 at 2016-03-14 19:33:47.438518016+00:00

....
....
....
I0314 19:34:02.317438 49961 process.cpp:2494] Resuming reaper(1)@172.31.14.224:50909 at 2016-03-14 19:34:02.317424896+00:00
I0314 19:34:02.331591 49963 process.cpp:2451] Dropping event for process __waiter__(811)@172.31.14.224:50909
I0314 19:34:02.331672 49949 process.cpp:2494] Resuming (5517)@172.31.14.224:50909 at 2016-03-14 19:34:02.331662080+00:00
I0314 19:34:02.417901 49957 process.cpp:2494] Resuming reaper(1)@172.31.14.224:50909 at 2016-03-14 19:34:02.417890048+00:00
I0314 19:34:02.433084 49952 process.cpp:2494] Resuming (5517)@172.31.14.224:50909 at 2016-03-14 19:34:02.433073920+00:00
I0314 19:34:02.443238 49963 process.cpp:2451] Dropping event for process __waiter__(812)@172.31.14.224:50909
I0314 19:34:02.443359 49959 process.cpp:2494] Resuming __waiter__(813)@172.31.14.224:50909 at 2016-03-14 19:34:02.443347968+00:00
I0314 19:34:02.443444 49959 process.cpp:2599] Cleaning up __waiter__(813)@172.31.14.224:50909
I0314 19:34:02.443526 49951 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:34:02.443516928+00:00
../../src/tests/cluster.cpp:333: Failure
Failed to wait 15secs for wait
*** Aborted at 1457984042 (unix time) try "date -d @1457984042" if you are using GNU date ***
PC: @          0x171e368 testing::UnitTest::AddTestPartResult()
*** SIGSEGV (@0x0) received by PID 49933 (TID 0x7f0484060800) from PID 0; stack trace: ***
    @     0x7f047d7a7340 (unknown)
    @          0x171e368 testing::UnitTest::AddTestPartResult()
    @          0x1713067 testing::internal::AssertHelper::operator=()
    @           0xa71505 mesos::internal::tests::Cluster::Slaves::shutdown()
    @          0x105ff38 mesos::internal::tests::MesosTest::ShutdownSlaves()
    @          0x105fef9 mesos::internal::tests::MesosTest::Shutdown()
    @          0x16ca98b mesos::internal::tests::MemoryPressureMesosTest_CGROUPS_ROOT_Statistics_Test::TestBody()
    @          0x173bc64 testing::internal::HandleSehExceptionsInMethodIfSupported<>()
    @          0x1736bba testing::internal::HandleExceptionsInMethodIfSupported<>()
    @          0x17182cf testing::Test::Run()
    @          0x1718a52 testing::TestInfo::Run()
    @          0x1719098 testing::TestCase::Run()
    @          0x171f7e0 testing::internal::UnitTestImpl::RunAllTests()
    @          0x173c889 testing::internal::HandleSehExceptionsInMethodIfSupported<>()
    @          0x1737730 testing::internal::HandleExceptionsInMethodIfSupported<>()
    @          0x171e57c testing::UnitTest::Run()
    @           0xe21bd1 RUN_ALL_TESTS()
    @           0xe217bf main
    @     0x7f047d3f3ec5 (unknown)
    @           0x99dab9 (unknown)

Log from a successful run:

Repeating all tests (iteration 78) . . .

Note: Google Test filter = MemoryPressureMesosTest.CGROUPS_ROOT_Statistics-HierarchicalAllocator_BENCHMARK_Test.DeclineOffers:HierarchicalAllocator_BENCHMARK_Test.ResourceLabels:MesosContainerizerSlaveRecoveryTest.CGROUPS_ROOT_PerfRollForward:NetClsIsolatorTest.ROOT_CGROUPS_NetClsIsolate:NetClsIsolatorTest.ROOT_CGROUPS_ContainerStatus:PerfEventIsolatorTest.ROOT_CGROUPS_Sample:UserCgroupIsolatorTest/0.ROOT_CGROUPS_UserCgroup:UserCgroupIsolatorTest/1.ROOT_CGROUPS_UserCgroup:UserCgroupIsolatorTest/2.ROOT_CGROUPS_UserCgroup:OverlayBackendTest.ROOT_OVERLAYFS_OverlayFSBackend:CgroupsNoHierarchyTest.ROOT_CGROUPS_NOHIERARCHY_MountUnmountHierarchy:CgroupsAnyHierarchyWithPerfEventTest.ROOT_CGROUPS_Perf:PerfTest.ROOT_Events:PerfTest.ROOT_Sample:PerfTest.Parse:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/0:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/1:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/2:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/3:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/4:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/5:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/6:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/7:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/8:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/9:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/10:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/11:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/12:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/13:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/14:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/15:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/16:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/17:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/18:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/19:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/20:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/21:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/22:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/23:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/24:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/25:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/26:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/27:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/28:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/29:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/30:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/31:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/32:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/33:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/34:SlaveAndFrameworkCount/HierarchicalAllocator_BENCHMARK_Test.AddAndUpdateSlave/35:SlaveCount/Registrar_BENCHMARK_Test.Performance/0:SlaveCount/Registrar_BENCHMARK_Test.Performance/1:SlaveCount/Registrar_BENCHMARK_Test.Performance/2:SlaveCount/Registrar_BENCHMARK_Test.Performance/3
[==========] Running 1 test from 1 test case.
[----------] Global test environment set-up.
I0314 19:33:43.181629 49947 process.cpp:2494] Resuming reaper(1)@172.31.14.224:50909 at 2016-03-14 19:33:43.181604096+00:00
[----------] 1 test from MemoryPressureMesosTest
1+0 records in
1+0 records out
1048576 bytes (1.0 MB) copied, 0.000592723 s, 1.8 GB/s
[ RUN      ] MemoryPressureMesosTest.CGROUPS_ROOT_Statistics
I0314 19:33:43.184860 49933 process.cpp:2484] Spawned process files@172.31.14.224:50909
I0314 19:33:43.184883 49958 process.cpp:2494] Resuming files@172.31.14.224:50909 at 2016-03-14 19:33:43.184867072+00:00
I0314 19:33:43.185094 49951 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:43.184982016+00:00
I0314 19:33:43.206938 49933 process.cpp:2484] Spawned process (5385)@172.31.14.224:50909
I0314 19:33:43.206949 49952 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:43.206934016+00:00
I0314 19:33:43.206964 49955 process.cpp:2494] Resuming (5385)@172.31.14.224:50909 at 2016-03-14 19:33:43.206948096+00:00
I0314 19:33:43.214699 49933 leveldb.cpp:174] Opened db in 7.67105ms
I0314 19:33:43.216894 49933 leveldb.cpp:181] Compacted db in 2.156826ms
I0314 19:33:43.216948 49933 leveldb.cpp:196] Created db iterator in 17191ns
I0314 19:33:43.216971 49933 leveldb.cpp:202] Seeked to beginning of db in 1400ns
I0314 19:33:43.216985 49933 leveldb.cpp:271] Iterated through 0 keys in the db in 388ns
I0314 19:33:43.217025 49933 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0314 19:33:43.217140 49933 process.cpp:2484] Spawned process log-replica(78)@172.31.14.224:50909
I0314 19:33:43.217180 49949 process.cpp:2494] Resuming log-replica(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.217156096+00:00
I0314 19:33:43.217300 49933 process.cpp:2484] Spawned process (5386)@172.31.14.224:50909
I0314 19:33:43.217317 49954 process.cpp:2494] Resuming (5386)@172.31.14.224:50909 at 2016-03-14 19:33:43.217294080+00:00
I0314 19:33:43.217387 49933 process.cpp:2484] Spawned process log(78)@172.31.14.224:50909
I0314 19:33:43.217502 49954 process.cpp:2494] Resuming log-reader(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.217495040+00:00
I0314 19:33:43.217535 49933 process.cpp:2484] Spawned process log-reader(78)@172.31.14.224:50909
I0314 19:33:43.217520 49953 process.cpp:2494] Resuming log(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.217502976+00:00
I0314 19:33:43.217633 49933 process.cpp:2484] Spawned process log-writer(78)@172.31.14.224:50909
I0314 19:33:43.217660 49957 process.cpp:2494] Resuming log-writer(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.217645056+00:00
I0314 19:33:43.217680 49953 process.cpp:2484] Spawned process log-recover(78)@172.31.14.224:50909
I0314 19:33:43.217679 49952 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.217670912+00:00
I0314 19:33:43.217716 49957 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:43.217705984+00:00
I0314 19:33:43.217716 49962 process.cpp:2494] Resuming log-recover(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.217686016+00:00
I0314 19:33:43.217761 49962 recover.cpp:447] Starting replica recovery
I0314 19:33:43.217757 49947 process.cpp:2494] Resuming (5387)@172.31.14.224:50909 at 2016-03-14 19:33:43.217742080+00:00
I0314 19:33:43.217767 49933 process.cpp:2484] Spawned process (5387)@172.31.14.224:50909
I0314 19:33:43.217892 49949 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:43.217882880+00:00
I0314 19:33:43.217939 49953 process.cpp:2494] Resuming log-replica(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.217929984+00:00
I0314 19:33:43.218019 49949 process.cpp:2494] Resuming log-recover(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.218011904+00:00
I0314 19:33:43.218034 49933 process.cpp:2484] Spawned process registrar(78)@172.31.14.224:50909
I0314 19:33:43.218051 49949 recover.cpp:473] Replica is in EMPTY status
I0314 19:33:43.218061 49956 process.cpp:2494] Resuming registrar(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.218042112+00:00
I0314 19:33:43.218101 49933 process.cpp:2484] Spawned process standalone-master-detector(232)@172.31.14.224:50909
I0314 19:33:43.218128 49950 process.cpp:2494] Resuming standalone-master-detector(232)@172.31.14.224:50909 at 2016-03-14 19:33:43.218109952+00:00
I0314 19:33:43.218215 49949 process.cpp:2484] Spawned process log-recover-protocol(155)@172.31.14.224:50909
I0314 19:33:43.218230 49960 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.218213120+00:00
I0314 19:33:43.218276 49962 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:43.218263040+00:00
I0314 19:33:43.218255 49948 process.cpp:2494] Resuming log-recover-protocol(155)@172.31.14.224:50909 at 2016-03-14 19:33:43.218224128+00:00
I0314 19:33:43.218231 49952 process.cpp:2494] Resuming authorizer(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.218221056+00:00
I0314 19:33:43.218369 49948 recover.cpp:129] Starting to wait for enough quorum of replicas before running recovery protocol, expected quroum size: 1
I0314 19:33:43.218374 49933 process.cpp:2484] Spawned process authorizer(78)@172.31.14.224:50909
I0314 19:33:43.218478 49952 process.cpp:2494] Resuming (5386)@172.31.14.224:50909 at 2016-03-14 19:33:43.218470912+00:00
I0314 19:33:43.218614 49948 process.cpp:2484] Spawned process __latch__(1923)@172.31.14.224:50909
I0314 19:33:43.218642 49961 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.218621952+00:00
I0314 19:33:43.218653 49957 process.cpp:2494] Resuming __latch__(1923)@172.31.14.224:50909 at 2016-03-14 19:33:43.218643968+00:00

...
...
...
I0314 19:33:43.291642 49948 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:43.291632896+00:00
I0314 19:33:43.291733 49948 pid.cpp:93] Attempting to parse 'scheduler-0ee20155-6b2a-4f05-b30b-61e79bdec7cc@172.31.14.224:50909' into a PID
I0314 19:33:43.291787 49948 master.cpp:5495] Authenticating scheduler-0ee20155-6b2a-4f05-b30b-61e79bdec7cc@172.31.14.224:50909
I0314 19:33:43.291888 49956 process.cpp:2494] Resuming crammd5_authenticator(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.291878912+00:00
I0314 19:33:43.291937 49956 authenticator.cpp:413] Starting authentication session for crammd5_authenticatee(155)@172.31.14.224:50909
I0314 19:33:43.292019 49956 process.cpp:2484] Spawned process crammd5_authenticator_session(155)@172.31.14.224:50909
I0314 19:33:43.292021 49960 process.cpp:2494] Resuming crammd5_authenticator_session(155)@172.31.14.224:50909 at 2016-03-14 19:33:43.292011008+00:00
I0314 19:33:43.292146 49958 process.cpp:2494] Resuming (5413)@172.31.14.224:50909 at 2016-03-14 19:33:43.292137984+00:00
I0314 19:33:43.292171 49960 authenticator.cpp:98] Creating new server SASL connection
I0314 19:33:43.292275 49956 process.cpp:2494] Resuming (5408)@172.31.14.224:50909 at 2016-03-14 19:33:43.292264960+00:00
I0314 19:33:43.292294 49958 process.cpp:2599] Cleaning up (5413)@172.31.14.224:50909
I0314 19:33:43.292385 49954 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:43.292375040+00:00
I0314 19:33:43.292392 49955 process.cpp:2494] Resuming (5399)@172.31.14.224:50909 at 2016-03-14 19:33:43.292382976+00:00
I0314 19:33:43.292400 49956 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.292392960+00:00
I0314 19:33:43.292599 49962 process.cpp:2494] Resuming crammd5_authenticatee(155)@172.31.14.224:50909 at 2016-03-14 19:33:43.292590080+00:00
I0314 19:33:43.292670 49962 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
I0314 19:33:43.292701 49962 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I0314 19:33:43.292716 49955 process.cpp:2484] Spawned process (5414)@172.31.14.224:50909
I0314 19:33:43.292739 49952 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.292730112+00:00
I0314 19:33:43.292765 49950 process.cpp:2494] Resuming crammd5_authenticator_session(155)@172.31.14.224:50909 at 2016-03-14 19:33:43.292756992+00:00
I0314 19:33:43.292752 49951 process.cpp:2494] Resuming (5414)@172.31.14.224:50909 at 2016-03-14 19:33:43.292741120+00:00
I0314 19:33:43.292855 49950 authenticator.cpp:203] Received SASL authentication start
I0314 19:33:43.292914 49950 authenticator.cpp:325] Authentication requires more steps
I0314 19:33:43.292966 49951 provisioner.cpp:245] Provisioner recovery complete
I0314 19:33:43.293001 49950 process.cpp:2494] Resuming crammd5_authenticatee(155)@172.31.14.224:50909 at 2016-03-14 19:33:43.292992000+00:00
I0314 19:33:43.293076 49950 authenticatee.cpp:258] Received SASL authentication step
I0314 19:33:43.293083 49958 process.cpp:2494] Resuming (5408)@172.31.14.224:50909 at 2016-03-14 19:33:43.293074944+00:00
I0314 19:33:43.293191 49951 process.cpp:2599] Cleaning up (5414)@172.31.14.224:50909
I0314 19:33:43.293227 49956 process.cpp:2494] Resuming crammd5_authenticator_session(155)@172.31.14.224:50909 at 2016-03-14 19:33:43.293219072+00:00
I0314 19:33:43.293236 49962 process.cpp:2494] Resuming slave(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.293224960+00:00
I0314 19:33:43.293287 49956 authenticator.cpp:231] Received SASL authentication step
I0314 19:33:43.293269 49958 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:43.293260032+00:00
I0314 19:33:43.293321 49956 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: 'ip-172-31-14-224.us-west-1.compute.internal' server FQDN: 'ip-172-31-14-224.us-west-1.compute.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0314 19:33:43.293365 49956 auxprop.cpp:179] Looking up auxiliary property '*userPassword'
I0314 19:33:43.293375 49962 slave.cpp:4565] Finished recovery
I0314 19:33:43.293395 49948 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.293385984+00:00
I0314 19:33:43.293397 49956 auxprop.cpp:179] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0314 19:33:43.293485 49956 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: 'ip-172-31-14-224.us-west-1.compute.internal' server FQDN: 'ip-172-31-14-224.us-west-1.compute.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0314 19:33:43.293510 49956 auxprop.cpp:129] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0314 19:33:43.293521 49956 auxprop.cpp:129] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0314 19:33:43.293539 49956 authenticator.cpp:317] Authentication success
I0314 19:33:43.293635 49958 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:43.293626880+00:00
I0314 19:33:43.293670 49949 process.cpp:2494] Resuming standalone-master-detector(233)@172.31.14.224:50909 at 2016-03-14 19:33:43.293658880+00:00
I0314 19:33:43.293694 49958 master.cpp:5525] Successfully authenticated principal 'test-principal' at scheduler-0ee20155-6b2a-4f05-b30b-61e79bdec7cc@172.31.14.224:50909
I0314 19:33:43.293678 49957 process.cpp:2494] Resuming crammd5_authenticator(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.293668096+00:00
I0314 19:33:43.293706 49962 slave.cpp:4737] Querying resource estimator for oversubscribable resources
I0314 19:33:43.293671 49951 process.cpp:2494] Resuming crammd5_authenticatee(155)@172.31.14.224:50909 at 2016-03-14 19:33:43.293661952+00:00
I0314 19:33:43.293794 49957 authenticator.cpp:431] Authentication session cleanup for crammd5_authenticatee(155)@172.31.14.224:50909
I0314 19:33:43.293843 49951 authenticatee.cpp:298] Authentication success
I0314 19:33:43.293845 49949 process.cpp:2494] Resuming (5411)@172.31.14.224:50909 at 2016-03-14 19:33:43.293838080+00:00
I0314 19:33:43.293887 49952 process.cpp:2494] Resuming crammd5_authenticator_session(155)@172.31.14.224:50909 at 2016-03-14 19:33:43.293878016+00:00
I0314 19:33:43.293926 49960 process.cpp:2494] Resuming scheduler-0ee20155-6b2a-4f05-b30b-61e79bdec7cc@172.31.14.224:50909 at 2016-03-14 19:33:43.293914112+00:00
I0314 19:33:43.293952 49962 pid.cpp:93] Attempting to parse 'master@172.31.14.224:50909' into a PID
I0314 19:33:43.293949 49954 process.cpp:2494] Resuming (5410)@172.31.14.224:50909 at 2016-03-14 19:33:43.293938944+00:00
I0314 19:33:43.293941 49952 process.cpp:2599] Cleaning up crammd5_authenticator_session(155)@172.31.14.224:50909
I0314 19:33:43.294034 49954 status_update_manager.cpp:174] Pausing sending status updates
I0314 19:33:43.293997 49962 slave.cpp:796] New master detected at master@172.31.14.224:50909
I0314 19:33:43.294059 49950 process.cpp:2494] Resuming crammd5_authenticatee(155)@172.31.14.224:50909 at 2016-03-14 19:33:43.294048000+00:00
I0314 19:33:43.294092 49959 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:43.294084096+00:00
I0314 19:33:43.294106 49950 process.cpp:2599] Cleaning up crammd5_authenticatee(155)@172.31.14.224:50909
I0314 19:33:43.294127 49962 slave.cpp:859] Authenticating with master master@172.31.14.224:50909
I0314 19:33:43.294165 49962 slave.cpp:864] Using default CRAM-MD5 authenticatee
I0314 19:33:43.294242 49962 process.cpp:2484] Spawned process crammd5_authenticatee(156)@172.31.14.224:50909
I0314 19:33:43.294261 49956 process.cpp:2494] Resuming crammd5_authenticatee(156)@172.31.14.224:50909 at 2016-03-14 19:33:43.294248960+00:00
I0314 19:33:43.294303 49960 sched.cpp:471] Successfully authenticated with master master@172.31.14.224:50909
I0314 19:33:43.294333 49960 sched.cpp:776] Sending SUBSCRIBE call to master@172.31.14.224:50909
I0314 19:33:43.294345 49956 authenticatee.cpp:121] Creating new client SASL connection
I0314 19:33:43.294333 49962 slave.cpp:832] Detecting new master
I0314 19:33:43.294361 49960 pid.cpp:93] Attempting to parse 'master@172.31.14.224:50909' into a PID
I0314 19:33:43.294378 49953 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:43.294369024+00:00
I0314 19:33:43.294483 49960 sched.cpp:809] Will retry registration in 1.303686606secs if necessary
I0314 19:33:43.294497 49962 slave.cpp:4751] Received oversubscribable resources  from the resource estimator
I0314 19:33:43.294494 49954 process.cpp:2494] Resuming standalone-master-detector(233)@172.31.14.224:50909 at 2016-03-14 19:33:43.294483968+00:00
I0314 19:33:43.294502 49953 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:43.294494976+00:00
I0314 19:33:43.294690 49953 master.cpp:2231] Received SUBSCRIBE call for framework 'default' at scheduler-0ee20155-6b2a-4f05-b30b-61e79bdec7cc@172.31.14.224:50909
I0314 19:33:43.294745 49953 master.cpp:1750] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0314 19:33:43.294844 49951 process.cpp:2494] Resuming authorizer(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.294835968+00:00
I0314 19:33:43.294885 49953 pid.cpp:93] Attempting to parse 'slave(78)@172.31.14.224:50909' into a PID
I0314 19:33:43.294927 49953 master.cpp:5495] Authenticating slave(78)@172.31.14.224:50909
I0314 19:33:43.294996 49954 process.cpp:2494] Resuming crammd5_authenticator(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.294989056+00:00
I0314 19:33:43.295043 49954 authenticator.cpp:413] Starting authentication session for crammd5_authenticatee(156)@172.31.14.224:50909
I0314 19:33:43.295081 49953 master.cpp:2302] Subscribing framework default with checkpointing disabled and capabilities [  ]
I0314 19:33:43.295117 49954 process.cpp:2484] Spawned process crammd5_authenticator_session(156)@172.31.14.224:50909
I0314 19:33:43.295147 49950 process.cpp:2494] Resuming crammd5_authenticator_session(156)@172.31.14.224:50909 at 2016-03-14 19:33:43.295137024+00:00
I0314 19:33:43.295284 49952 process.cpp:2494] Resuming (5385)@172.31.14.224:50909 at 2016-03-14 19:33:43.295275008+00:00
I0314 19:33:43.295310 49950 authenticator.cpp:98] Creating new server SASL connection
I0314 19:33:43.295361 49957 process.cpp:2494] Resuming metrics@172.31.14.224:50909 at 2016-03-14 19:33:43.295353088+00:00
I0314 19:33:43.295423 49952 hierarchical.cpp:265] Added framework 32379989-c9d4-4cb0-8f56-ed0f09185040-0000
I0314 19:33:43.295464 49960 process.cpp:2494] Resuming scheduler-0ee20155-6b2a-4f05-b30b-61e79bdec7cc@172.31.14.224:50909 at 2016-03-14 19:33:43.295452928+00:00
I0314 19:33:43.295485 49952 hierarchical.cpp:1453] No resources available to allocate!
I0314 19:33:43.295552 49952 hierarchical.cpp:1548] No inverse offers to send out!
I0314 19:33:43.295574 49960 pid.cpp:93] Attempting to parse 'master@172.31.14.224:50909' into a PID
I0314 19:33:43.295584 49952 hierarchical.cpp:1130] Performed allocation for 0 slaves in 135389ns
I0314 19:33:43.295613 49960 sched.cpp:703] Framework registered with 32379989-c9d4-4cb0-8f56-ed0f09185040-0000
I0314 19:33:43.295667 49960 sched.cpp:717] Scheduler::registered took 21001ns
I0314 19:33:43.295773 49953 process.cpp:2494] Resuming crammd5_authenticatee(156)@172.31.14.224:50909 at 2016-03-14 19:33:43.295759872+00:00
I0314 19:33:43.295850 49953 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
I0314 19:33:43.295882 49953 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I0314 19:33:43.295939 49956 process.cpp:2494] Resuming crammd5_authenticator_session(156)@172.31.14.224:50909 at 2016-03-14 19:33:43.295930880+00:00
I0314 19:33:43.296001 49956 authenticator.cpp:203] Received SASL authentication start
I0314 19:33:43.296053 49956 authenticator.cpp:325] Authentication requires more steps
I0314 19:33:43.296110 49957 process.cpp:2494] Resuming crammd5_authenticatee(156)@172.31.14.224:50909 at 2016-03-14 19:33:43.296102912+00:00
I0314 19:33:43.296176 49957 authenticatee.cpp:258] Received SASL authentication step
I0314 19:33:43.296252 49957 process.cpp:2494] Resuming crammd5_authenticator_session(156)@172.31.14.224:50909 at 2016-03-14 19:33:43.296246016+00:00
I0314 19:33:43.296315 49957 authenticator.cpp:231] Received SASL authentication step
I0314 19:33:43.296352 49957 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: 'ip-172-31-14-224.us-west-1.compute.internal' server FQDN: 'ip-172-31-14-224.us-west-1.compute.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0314 19:33:43.296375 49957 auxprop.cpp:179] Looking up auxiliary property '*userPassword'
I0314 19:33:43.296403 49957 auxprop.cpp:179] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0314 19:33:43.296437 49957 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: 'ip-172-31-14-224.us-west-1.compute.internal' server FQDN: 'ip-172-31-14-224.us-west-1.compute.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0314 19:33:43.296459 49957 auxprop.cpp:129] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0314 19:33:43.296470 49957 auxprop.cpp:129] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0314 19:33:43.296485 49957 authenticator.cpp:317] Authentication success
I0314 19:33:43.296547 49960 process.cpp:2494] Resuming crammd5_authenticatee(156)@172.31.14.224:50909 at 2016-03-14 19:33:43.296538880+00:00
I0314 19:33:43.296581 49959 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:43.296571904+00:00
I0314 19:33:43.296619 49960 authenticatee.cpp:298] Authentication success
I0314 19:33:43.296612 49961 process.cpp:2494] Resuming crammd5_authenticator(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.296602112+00:00
I0314 19:33:43.296625 49959 master.cpp:5525] Successfully authenticated principal 'test-principal' at slave(78)@172.31.14.224:50909
I0314 19:33:43.296713 49961 authenticator.cpp:431] Authentication session cleanup for crammd5_authenticatee(156)@172.31.14.224:50909
I0314 19:33:43.296720 49950 process.cpp:2494] Resuming slave(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.296709120+00:00
I0314 19:33:43.296764 49947 process.cpp:2494] Resuming crammd5_authenticator_session(156)@172.31.14.224:50909 at 2016-03-14 19:33:43.296755968+00:00
I0314 19:33:43.296836 49958 process.cpp:2494] Resuming crammd5_authenticatee(156)@172.31.14.224:50909 at 2016-03-14 19:33:43.296827904+00:00
I0314 19:33:43.296877 49947 process.cpp:2599] Cleaning up crammd5_authenticator_session(156)@172.31.14.224:50909
I0314 19:33:43.296926 49958 process.cpp:2599] Cleaning up crammd5_authenticatee(156)@172.31.14.224:50909
I0314 19:33:43.296947 49949 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:43.296937984+00:00
I0314 19:33:43.297055 49959 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:43.297046016+00:00
I0314 19:33:43.297135 49950 slave.cpp:927] Successfully authenticated with master master@172.31.14.224:50909
I0314 19:33:43.297238 49950 slave.cpp:1321] Will retry registration in 14.314099ms if necessary
I0314 19:33:43.297252 49962 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:43.297242880+00:00
I0314 19:33:43.297412 49962 master.cpp:4206] Registering slave at slave(78)@172.31.14.224:50909 (ip-172-31-14-224.us-west-1.compute.internal) with id 32379989-c9d4-4cb0-8f56-ed0f09185040-S0
I0314 19:33:43.297551 49953 process.cpp:2494] Resuming registrar(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.297542912+00:00
I0314 19:33:43.297775 49953 registrar.cpp:439] Applied 1 operations in 41921ns; attempting to update the 'registry'
I0314 19:33:43.297966 49951 process.cpp:2494] Resuming (5387)@172.31.14.224:50909 at 2016-03-14 19:33:43.297957120+00:00
I0314 19:33:43.298131 49957 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.298121984+00:00
I0314 19:33:43.298168 49955 process.cpp:2494] Resuming __latch__(1930)@172.31.14.224:50909 at 2016-03-14 19:33:43.298153984+00:00
I0314 19:33:43.298142 49953 process.cpp:2484] Spawned process __latch__(1930)@172.31.14.224:50909
I0314 19:33:43.298321 49948 process.cpp:2494] Resuming log-writer(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.298311936+00:00
I0314 19:33:43.298379 49948 log.cpp:683] Attempting to append 440 bytes to the log
I0314 19:33:43.298456 49955 process.cpp:2494] Resuming log-coordinator(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.298447872+00:00
I0314 19:33:43.298516 49955 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3
I0314 19:33:43.298617 49955 process.cpp:2484] Spawned process log-write(389)@172.31.14.224:50909
I0314 19:33:43.298653 49959 process.cpp:2494] Resuming log-write(389)@172.31.14.224:50909 at 2016-03-14 19:33:43.298644992+00:00
I0314 19:33:43.298642 49952 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.298633984+00:00
I0314 19:33:43.298744 49959 process.cpp:2494] Resuming (5386)@172.31.14.224:50909 at 2016-03-14 19:33:43.298737920+00:00
I0314 19:33:43.298877 49954 process.cpp:2494] Resuming log-write(389)@172.31.14.224:50909 at 2016-03-14 19:33:43.298866944+00:00
I0314 19:33:43.298993 49951 process.cpp:2494] Resuming (5386)@172.31.14.224:50909 at 2016-03-14 19:33:43.298984960+00:00
I0314 19:33:43.299103 49956 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.299092992+00:00
I0314 19:33:43.299126 49953 process.cpp:2494] Resuming (5415)@172.31.14.224:50909 at 2016-03-14 19:33:43.299117056+00:00
I0314 19:33:43.299109 49951 process.cpp:2484] Spawned process (5415)@172.31.14.224:50909
I0314 19:33:43.299211 49955 process.cpp:2494] Resuming (5415)@172.31.14.224:50909 at 2016-03-14 19:33:43.299202048+00:00
I0314 19:33:43.299248 49947 process.cpp:2494] Resuming log-write(389)@172.31.14.224:50909 at 2016-03-14 19:33:43.299238912+00:00
I0314 19:33:43.299315 49954 process.cpp:2494] Resuming log-replica(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.299304960+00:00
I0314 19:33:43.299437 49954 replica.cpp:537] Replica received write request for position 3 from (5415)@172.31.14.224:50909
I0314 19:33:43.301748 49954 leveldb.cpp:341] Persisting action (459 bytes) to leveldb took 2.267305ms
I0314 19:33:43.301784 49954 replica.cpp:712] Persisted action at 3
I0314 19:33:43.301846 49954 process.cpp:2494] Resuming (5415)@172.31.14.224:50909 at 2016-03-14 19:33:43.301839104+00:00
I0314 19:33:43.301949 49954 process.cpp:2599] Cleaning up (5415)@172.31.14.224:50909
I0314 19:33:43.301949 49961 process.cpp:2494] Resuming log-write(389)@172.31.14.224:50909 at 2016-03-14 19:33:43.301939968+00:00
I0314 19:33:43.302023 49955 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:43.302014976+00:00
I0314 19:33:43.302067 49950 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.302059008+00:00
I0314 19:33:43.302127 49959 process.cpp:2494] Resuming log-coordinator(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.302117888+00:00
I0314 19:33:43.302220 49961 process.cpp:2599] Cleaning up log-write(389)@172.31.14.224:50909
I0314 19:33:43.302299 49955 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:43.302289920+00:00
I0314 19:33:43.302361 49956 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.302351104+00:00
I0314 19:33:43.302373 49954 process.cpp:2494] Resuming (5386)@172.31.14.224:50909 at 2016-03-14 19:33:43.302363904+00:00
I0314 19:33:43.302489 49959 process.cpp:2494] Resuming log-replica(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.302479872+00:00
I0314 19:33:43.302508 49962 process.cpp:2494] Resuming log-coordinator(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.302497024+00:00
I0314 19:33:43.302554 49959 replica.cpp:691] Replica received learned notice for position 3 from @0.0.0.0:0
I0314 19:33:43.304344 49959 leveldb.cpp:341] Persisting action (461 bytes) to leveldb took 1.758658ms
I0314 19:33:43.304381 49959 replica.cpp:712] Persisted action at 3
I0314 19:33:43.304401 49959 replica.cpp:697] Replica learned APPEND action at position 3
I0314 19:33:43.304509 49948 process.cpp:2494] Resuming log-coordinator(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.304500992+00:00
I0314 19:33:43.304702 49949 process.cpp:2494] Resuming (5387)@172.31.14.224:50909 at 2016-03-14 19:33:43.304692992+00:00
I0314 19:33:43.305217 49961 process.cpp:2494] Resuming __latch__(1930)@172.31.14.224:50909 at 2016-03-14 19:33:43.305207040+00:00
I0314 19:33:43.305270 49961 process.cpp:2599] Cleaning up __latch__(1930)@172.31.14.224:50909
I0314 19:33:43.305341 49957 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:43.305331968+00:00
I0314 19:33:43.305382 49947 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.305372928+00:00
I0314 19:33:43.305460 49947 process.cpp:2494] Resuming registrar(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.305454080+00:00
I0314 19:33:43.305577 49947 registrar.cpp:484] Successfully updated the 'registry' in 7.748864ms
I0314 19:33:43.305735 49948 process.cpp:2494] Resuming log-writer(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.305725952+00:00
I0314 19:33:43.305757 49950 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:43.305746944+00:00
I0314 19:33:43.305783 49948 log.cpp:702] Attempting to truncate the log to 3
I0314 19:33:43.305902 49960 process.cpp:2494] Resuming log-coordinator(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.305891072+00:00
I0314 19:33:43.305969 49960 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 4
I0314 19:33:43.306107 49950 process.cpp:2484] Spawned process slave-observer(78)@172.31.14.224:50909
I0314 19:33:43.306128 49949 process.cpp:2494] Resuming slave-observer(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.306117120+00:00
I0314 19:33:43.306140 49955 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.306130944+00:00
I0314 19:33:43.306114 49960 process.cpp:2484] Spawned process log-write(390)@172.31.14.224:50909
I0314 19:33:43.306155 49959 process.cpp:2494] Resuming log-write(390)@172.31.14.224:50909 at 2016-03-14 19:33:43.306144000+00:00
I0314 19:33:43.306196 49947 process.cpp:2494] Resuming slave(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.306185984+00:00
I0314 19:33:43.306273 49953 process.cpp:2494] Resuming (5386)@172.31.14.224:50909 at 2016-03-14 19:33:43.306262016+00:00
I0314 19:33:43.306285 49947 slave.cpp:3482] Received ping from slave-observer(78)@172.31.14.224:50909
I0314 19:33:43.306308 49954 process.cpp:2494] Resuming (5385)@172.31.14.224:50909 at 2016-03-14 19:33:43.306297088+00:00
I0314 19:33:43.306401 49959 process.cpp:2494] Resuming log-write(390)@172.31.14.224:50909 at 2016-03-14 19:33:43.306391040+00:00
I0314 19:33:43.306417 49960 process.cpp:2494] Resuming slave-observer(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.306407936+00:00
I0314 19:33:43.306385 49950 master.cpp:4274] Registered slave 32379989-c9d4-4cb0-8f56-ed0f09185040-S0 at slave(78)@172.31.14.224:50909 (ip-172-31-14-224.us-west-1.compute.internal) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0314 19:33:43.306484 49947 slave.cpp:971] Registered with master master@172.31.14.224:50909; given slave ID 32379989-c9d4-4cb0-8f56-ed0f09185040-S0
I0314 19:33:43.306524 49947 fetcher.cpp:81] Clearing fetcher cache
I0314 19:33:43.306568 49954 hierarchical.cpp:473] Added slave 32379989-c9d4-4cb0-8f56-ed0f09185040-S0 (ip-172-31-14-224.us-west-1.compute.internal) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: )
I0314 19:33:43.306592 49948 process.cpp:2494] Resuming (5410)@172.31.14.224:50909 at 2016-03-14 19:33:43.306584064+00:00
I0314 19:33:43.306588 49959 process.cpp:2494] Resuming (5386)@172.31.14.224:50909 at 2016-03-14 19:33:43.306580992+00:00
I0314 19:33:43.306650 49948 status_update_manager.cpp:181] Resuming sending status updates
I0314 19:33:43.306668 49947 slave.cpp:994] Checkpointing SlaveInfo to '/tmp/MemoryPressureMesosTest_CGROUPS_ROOT_Statistics_RYOTzy/meta/slaves/32379989-c9d4-4cb0-8f56-ed0f09185040-S0/slave.info'
I0314 19:33:43.306740 49959 process.cpp:2484] Spawned process (5416)@172.31.14.224:50909
I0314 19:33:43.306757 49950 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.306746880+00:00
I0314 19:33:43.306780 49961 process.cpp:2494] Resuming (5416)@172.31.14.224:50909 at 2016-03-14 19:33:43.306770944+00:00
I0314 19:33:43.306846 49948 process.cpp:2494] Resuming log-write(390)@172.31.14.224:50909 at 2016-03-14 19:33:43.306839040+00:00
I0314 19:33:43.306880 49950 process.cpp:2494] Resuming log-replica(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.306871040+00:00
I0314 19:33:43.306891 49954 hierarchical.cpp:1427] Allocating cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 32379989-c9d4-4cb0-8f56-ed0f09185040-S0 to framework 32379989-c9d4-4cb0-8f56-ed0f09185040-0000
I0314 19:33:43.306926 49947 slave.cpp:1030] Forwarding total oversubscribed resources
I0314 19:33:43.306954 49950 replica.cpp:537] Replica received write request for position 4 from (5416)@172.31.14.224:50909
I0314 19:33:43.306999 49957 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:43.306990080+00:00
I0314 19:33:43.307092 49957 master.cpp:4618] Received update of slave 32379989-c9d4-4cb0-8f56-ed0f09185040-S0 at slave(78)@172.31.14.224:50909 (ip-172-31-14-224.us-west-1.compute.internal) with total oversubscribed resources
I0314 19:33:43.307237 49954 hierarchical.cpp:1548] No inverse offers to send out!
I0314 19:33:43.307232 49952 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:43.307224064+00:00
I0314 19:33:43.307283 49954 hierarchical.cpp:1150] Performed allocation for slave 32379989-c9d4-4cb0-8f56-ed0f09185040-S0 in 671960ns
I0314 19:33:43.307533 49954 hierarchical.cpp:531] Slave 32379989-c9d4-4cb0-8f56-ed0f09185040-S0 (ip-172-31-14-224.us-west-1.compute.internal) updated with oversubscribed resources  (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000])
I0314 19:33:43.307545 49952 master.cpp:5324] Sending 1 offers to framework 32379989-c9d4-4cb0-8f56-ed0f09185040-0000 (default) at scheduler-0ee20155-6b2a-4f05-b30b-61e79bdec7cc@172.31.14.224:50909
I0314 19:33:43.307648 49954 hierarchical.cpp:1453] No resources available to allocate!
I0314 19:33:43.307684 49947 process.cpp:2494] Resuming scheduler-0ee20155-6b2a-4f05-b30b-61e79bdec7cc@172.31.14.224:50909 at 2016-03-14 19:33:43.307675904+00:00
I0314 19:33:43.307694 49954 hierarchical.cpp:1548] No inverse offers to send out!
I0314 19:33:43.307749 49954 hierarchical.cpp:1150] Performed allocation for slave 32379989-c9d4-4cb0-8f56-ed0f09185040-S0 in 170369ns
I0314 19:33:43.307818 49947 pid.cpp:93] Attempting to parse 'master@172.31.14.224:50909' into a PID
I0314 19:33:43.307857 49947 sched.cpp:849] Received 1 offers
I0314 19:33:43.307880 49947 pid.cpp:93] Attempting to parse 'slave(78)@172.31.14.224:50909' into a PID
I0314 19:33:43.308018 49947 sched.cpp:873] Scheduler::resourceOffers took 94884ns
I0314 19:33:43.308037 49952 process.cpp:2494] Resuming __latch__(1929)@172.31.14.224:50909 at 2016-03-14 19:33:43.308025088+00:00
I0314 19:33:43.308074 49952 process.cpp:2599] Cleaning up __latch__(1929)@172.31.14.224:50909
I0314 19:33:43.308189 49962 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:43.308177920+00:00
I0314 19:33:43.308214 49956 process.cpp:2494] Resuming __waiter__(796)@172.31.14.224:50909 at 2016-03-14 19:33:43.308204032+00:00
I0314 19:33:43.308277 49957 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.308267008+00:00
I0314 19:33:43.308357 49956 process.cpp:2599] Cleaning up __waiter__(796)@172.31.14.224:50909
I0314 19:33:43.308434 49954 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:43.308422912+00:00
I0314 19:33:43.308517 49933 resources.cpp:572] Parsing resources as JSON failed: cpus:1;mem:256;disk:1024
Trying semicolon-delimited string format instead
I0314 19:33:43.308816 49955 process.cpp:2494] Resuming scheduler-0ee20155-6b2a-4f05-b30b-61e79bdec7cc@172.31.14.224:50909 at 2016-03-14 19:33:43.308807936+00:00
I0314 19:33:43.308845 49948 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.308836096+00:00
I0314 19:33:43.308857 49959 process.cpp:2494] Resuming __latch__(1931)@172.31.14.224:50909 at 2016-03-14 19:33:43.308847104+00:00
I0314 19:33:43.308847 49933 process.cpp:2484] Spawned process __latch__(1931)@172.31.14.224:50909
I0314 19:33:43.308965 49933 process.cpp:2484] Spawned process __waiter__(797)@172.31.14.224:50909
I0314 19:33:43.308987 49955 pid.cpp:93] Attempting to parse 'master@172.31.14.224:50909' into a PID
I0314 19:33:43.308982 49948 process.cpp:2494] Resuming __waiter__(797)@172.31.14.224:50909 at 2016-03-14 19:33:43.308976128+00:00
I0314 19:33:43.309111 49949 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:43.309103104+00:00
I0314 19:33:43.309182 49950 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 2.179307ms
I0314 19:33:43.309218 49950 replica.cpp:712] Persisted action at 4
I0314 19:33:43.309279 49950 process.cpp:2494] Resuming (5416)@172.31.14.224:50909 at 2016-03-14 19:33:43.309273088+00:00
I0314 19:33:43.309376 49947 process.cpp:2494] Resuming log-write(390)@172.31.14.224:50909 at 2016-03-14 19:33:43.309366016+00:00
I0314 19:33:43.309391 49950 process.cpp:2599] Cleaning up (5416)@172.31.14.224:50909
I0314 19:33:43.309463 49956 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:43.309455104+00:00
I0314 19:33:43.309490 49954 process.cpp:2494] Resuming log-coordinator(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.309480960+00:00
I0314 19:33:43.309530 49961 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.309519872+00:00
I0314 19:33:43.309629 49947 process.cpp:2599] Cleaning up log-write(390)@172.31.14.224:50909
I0314 19:33:43.309671 49949 master.cpp:3104] Processing ACCEPT call for offers: [ 32379989-c9d4-4cb0-8f56-ed0f09185040-O0 ] on slave 32379989-c9d4-4cb0-8f56-ed0f09185040-S0 at slave(78)@172.31.14.224:50909 (ip-172-31-14-224.us-west-1.compute.internal) for framework 32379989-c9d4-4cb0-8f56-ed0f09185040-0000 (default) at scheduler-0ee20155-6b2a-4f05-b30b-61e79bdec7cc@172.31.14.224:50909
I0314 19:33:43.309701 49950 process.cpp:2494] Resuming (5386)@172.31.14.224:50909 at 2016-03-14 19:33:43.309690112+00:00
I0314 19:33:43.309733 49949 master.cpp:2776] Authorizing framework principal 'test-principal' to launch task ca0c2383-9b8d-4c52-ab7b-a9361ce98682 as user 'root'
I0314 19:33:43.309746 49960 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.309734912+00:00
I0314 19:33:43.309700 49961 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:43.309692928+00:00
I0314 19:33:43.309902 49948 process.cpp:2494] Resuming authorizer(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.309893120+00:00
I0314 19:33:43.309932 49947 process.cpp:2494] Resuming log-coordinator(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.309924096+00:00
I0314 19:33:43.310029 49955 process.cpp:2494] Resuming log-replica(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.310014976+00:00
I0314 19:33:43.310075 49957 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.310065920+00:00
I0314 19:33:43.310107 49955 replica.cpp:691] Replica received learned notice for position 4 from @0.0.0.0:0
I0314 19:33:43.310128 49949 process.cpp:2484] Spawned process (5417)@172.31.14.224:50909
I0314 19:33:43.310104 49947 process.cpp:2494] Resuming (5417)@172.31.14.224:50909 at 2016-03-14 19:33:43.310095872+00:00
I0314 19:33:43.310407 49959 process.cpp:2494] Resuming master@172.31.14.224:50909 at 2016-03-14 19:33:43.310398976+00:00
I0314 19:33:43.310417 49947 process.cpp:2599] Cleaning up (5417)@172.31.14.224:50909
I0314 19:33:43.310510 49950 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:43.310500096+00:00
I0314 19:33:43.310534 49954 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:43.310523904+00:00
I0314 19:33:43.310796 49955 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 645915ns
I0314 19:33:43.310860 49955 leveldb.cpp:399] Deleting ~2 keys from leveldb took 31389ns
I0314 19:33:43.310889 49955 replica.cpp:712] Persisted action at 4
I0314 19:33:43.310912 49955 replica.cpp:697] Replica learned TRUNCATE action at position 4
I0314 19:33:43.310958 49959 master.hpp:177] Adding task ca0c2383-9b8d-4c52-ab7b-a9361ce98682 with resources cpus(*):1; mem(*):256; disk(*):1024 on slave 32379989-c9d4-4cb0-8f56-ed0f09185040-S0 (ip-172-31-14-224.us-west-1.compute.internal)
I0314 19:33:43.311017 49948 process.cpp:2494] Resuming log-coordinator(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.311008000+00:00
I0314 19:33:43.311075 49959 master.cpp:3589] Launching task ca0c2383-9b8d-4c52-ab7b-a9361ce98682 of framework 32379989-c9d4-4cb0-8f56-ed0f09185040-0000 (default) at scheduler-0ee20155-6b2a-4f05-b30b-61e79bdec7cc@172.31.14.224:50909 with resources cpus(*):1; mem(*):256; disk(*):1024 on slave 32379989-c9d4-4cb0-8f56-ed0f09185040-S0 at slave(78)@172.31.14.224:50909 (ip-172-31-14-224.us-west-1.compute.internal)
I0314 19:33:43.311223 49947 process.cpp:2494] Resuming (5387)@172.31.14.224:50909 at 2016-03-14 19:33:43.311214080+00:00
I0314 19:33:43.311228 49961 process.cpp:2494] Resuming slave(78)@172.31.14.224:50909 at 2016-03-14 19:33:43.311219968+00:00
I0314 19:33:43.311265 49950 process.cpp:2494] Resuming (5385)@172.31.14.224:50909 at 2016-03-14 19:33:43.311256064+00:00
I0314 19:33:43.311471 49961 pid.cpp:93] Attempting to parse 'scheduler-0ee20155-6b2a-4f05-b30b-61e79bdec7cc@172.31.14.224:50909' into a PID
I0314 19:33:43.311512 49961 slave.cpp:1361] Got assigned task ca0c2383-9b8d-4c52-ab7b-a9361ce98682 for framework 32379989-c9d4-4cb0-8f56-ed0f09185040-0000
I0314 19:33:43.311635 49961 resources.cpp:572] Parsing resources as JSON failed: cpus:0.1;mem:32
Trying semicolon-delimited string format instead
I0314 19:33:43.311669 49950 hierarchical.cpp:890] Recovered cpus(*):1; mem(*):768; ports(*):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):1; mem(*):256; disk(*):1024) on slave 32379989-c9d4-4cb0-8f56-ed0f09185040-S0 from framework 32379989-c9d4-4cb0-8f56-ed0f09185040-0000
I0314 19:33:43.311724 49950 hierarchical.cpp:927] Framework 32379989-c9d4-4cb0-8f56-ed0f09185040-0000 filtered slave 32379989-c9d4-4cb0-8f56-ed0f09185040-S0 for 5secs
I0314 19:33:43.311969 49961 slave.cpp:1480] Launching task ca0c2383-9b8d-4c52-ab7b-a9361ce98682 for framework 32379989-c9d4-4cb0-8f56-ed0f09185040-0000
I0314 19:33:43.312036 49961 resources.cpp:572] Parsing resources as JSON failed: cpus:0.1;mem:32
Trying semicolon-delimited string format instead
I0314 19:33:43.312388 49961 paths.cpp:528] Trying to chown '/tmp/MemoryPressureMesosTest_CGROUPS_ROOT_Statistics_RYOTzy/slaves/32379989-c9d4-4cb0-8f56-ed0f09185040-S0/frameworks/32379989-c9d4-4cb0-8f56-ed0f09185040-0000/executors/ca0c2383-9b8d-4c52-ab7b-a9361ce98682/runs/b66daaf4-8cb9-4251-8e4a-b0187e644a82' to user 'root'
I0314 19:33:43.314998 49961 slave.cpp:5367] Launching executor ca0c2383-9b8d-4c52-ab7b-a9361ce98682 of framework 32379989-c9d4-4cb0-8f56-ed0f09185040-0000 with resources cpus(*):0.1; mem(*):32 in work directory '/tmp/MemoryPressureMesosTest_CGROUPS_ROOT_Statistics_RYOTzy/slaves/32379989-c9d4-4cb0-8f56-ed0f09185040-S0/frameworks/32379989-c9d4-4cb0-8f56-ed0f09185040-0000/executors/ca0c2383-9b8d-4c52-ab7b-a9361ce98682/runs/b66daaf4-8cb9-4251-8e4a-b0187e644a82'
I0314 19:33:43.315131 49953 process.cpp:2494] Resuming files@172.31.14.224:50909 at 2016-03-14 19:33:43.315115008+00:00
I0314 19:33:43.315284 49951 process.cpp:2494] Resuming (5408)@172.31.14.224:50909 at 2016-03-14 19:33:43.315264000+00:00
I0314 19:33:43.315362 49961 slave.cpp:1698] Queuing task 'ca0c2383-9b8d-4c52-ab7b-a9361ce98682' for executor 'ca0c2383-9b8d-4c52-ab7b-a9361ce98682' of framework 32379989-c9d4-4cb0-8f56-ed0f09185040-0000
I0314 19:33:43.315377 49951 containerizer.cpp:666] Starting container 'b66daaf4-8cb9-4251-8e4a-b0187e644a82' for executor 'ca0c2383-9b8d-4c52-ab7b-a9361ce98682' of framework '32379989-c9d4-4cb0-8f56-ed0f09185040-0000'
I0314 19:33:43.315479 49961 slave.cpp:749] Successfully attached file '/tmp/MemoryPressureMesosTest_CGROUPS_ROOT_Statistics_RYOTzy/slaves/32379989-c9d4-4cb0-8f56-ed0f09185040-S0/frameworks/32379989-c9d4-4cb0-8f56-ed0f09185040-0000/executors/ca0c2383-9b8d-4c52-ab7b-a9361ce98682/runs/b66daaf4-8cb9-4251-8e4a-b0187e644a82'
I0314 19:33:43.315487 49951 process.cpp:2484] Spawned process (5418)@172.31.14.224:50909
I0314 19:33:43.315510 49953 process.cpp:2494] Resuming (5418)@172.31.14.224:50909 at 2016-03-14 19:33:43.315501056+00:00
I0314 19:33:43.316045 49954 process.cpp:2494] Resuming (5407)@172.31.14.224:50909 at 2016-03-14 19:33:43.316027904+00:00

...
...
...
I0314 19:33:46.663902 49955 process.cpp:2599] Cleaning up __latch__(1947)@172.31.14.224:50909
I0314 19:33:46.663952 49962 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.663943936+00:00
I0314 19:33:46.664016 49962 process.cpp:2494] Resuming __gc__@172.31.14.224:50909 at 2016-03-14 19:33:46.664011008+00:00
I0314 19:33:46.665400 49933 process.cpp:2795] Donating thread to files@172.31.14.224:50909 while waiting
I0314 19:33:46.665438 49933 process.cpp:2494] Resuming files@172.31.14.224:50909 at 2016-03-14 19:33:46.665432064+00:00
I0314 19:33:46.665464 49933 process.cpp:2599] Cleaning up files@172.31.14.224:50909
I0314 19:33:46.665539 49958 process.cpp:2494] Resuming help@172.31.14.224:50909 at 2016-03-14 19:33:46.665530112+00:00
[       OK ] MemoryPressureMesosTest.CGROUPS_ROOT_Statistics (3481 ms)
[----------] 1 test from MemoryPressureMesosTest (3481 ms total)

[----------] Global test environment tear-down
I0314 19:33:46.667393 49952 process.cpp:2494] Resuming reaper(1)@172.31.14.224:50909 at 2016-03-14 19:33:46.667375104+00:00
I0314 19:33:46.709632 49963 process.cpp:2451] Dropping event for process (5200)@172.31.14.224:50909
[==========] 1 test from 1 test case ran. (3557 ms total)
[  PASSED  ] 1 test.

Attachments

Issue Links

is related to

MESOS-3586 MemoryPressureMesosTest.CGROUPS_ROOT_Statistics and CGROUPS_ROOT_SlaveRecovery are flaky

Resolved

MESOS-4047 MemoryPressureMesosTest.CGROUPS_ROOT_SlaveRecovery is flaky

Resolved

MESOS-4053 MemoryPressureMesosTest tests fail on CentOS 6.6

Accepted

Activity

People

Assignee:: Unassigned

Reporter:: Greg Mann

Votes:: 0 Vote for this issue

Watchers:: 1 Start watching this issue

Dates

Created:: 14/Mar/16 19:51

Updated:: 12/Mar/19 14:12

Resolved:: 24/Jan/19 20:19