mesos-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Alexander Rukletsov (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (MESOS-1802) HealthCheckTest.HealthStatusChange is flaky on jenkins.
Date Thu, 24 Nov 2016 22:33:58 GMT

    [ https://issues.apache.org/jira/browse/MESOS-1802?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15694334#comment-15694334
] 

Alexander Rukletsov commented on MESOS-1802:
--------------------------------------------

I can reproduce it relatively easy by running _parallel_ {{make check}}. Here is a fresh log:
{noformat}
[ RUN      ] HealthCheckTest.HealthStatusChange
I1124 23:20:48.351884 4284416 exec.cpp:162] Version: 1.2.0
I1124 23:20:48.375592 3747840 exec.cpp:237] Executor registered on agent 6db7ef4d-7211-47be-98ba-ad590b528c69-S0
Received SUBSCRIBED event
Subscribed executor on alexr.speedportneo09012801000249
Received LAUNCH event
Starting task 1
/Users/alex/Projects/mesos/build/parallel/src/mesos-containerizer launch --command="{"shell":true,"value":"sleep
120"}" --help="false"
Forked command at 73286
Received task health update, healthy: true
rm: /private/tmp/z1PbfH/rG7Gha: No such file or directory
W1124 23:20:48.544631 3211264 health_checker.cpp:245] Health check failed 1 times consecutively:
COMMAND health check failed: Command returned exited with status 1
Received task health update, healthy: false
Received task health update, healthy: true
rm: /private/tmp/z1PbfH/rG7Gha: No such file or directory
../../../src/tests/health_check_tests.cpp:790: Failure
Value of: (find).get()
  Actual: 16-byte object <05-00 00-00 00-00 00-00 60-A9 62-1B B2-7F 00-00>
Expected: false
Which is: false
I1124 23:20:48.732457 4284416 exec.cpp:414] Executor asked to shutdown
Received SHUTDOWN event
Shutting down
Sending SIGTERM to process tree at pid 73286
W1124 23:20:48.747885 1064960 health_checker.cpp:245] Health check failed 1 times consecutively:
COMMAND health check failed: Command returned exited with status 1
rm: /private/tmp/z1PbfH/rG7Gha: No such file or directory
W1124 23:20:48.948562 3747840 health_checker.cpp:245] Health check failed 1 times consecutively:
COMMAND health check failed: Command returned exited with status 1
Sent SIGTERM to the following process trees:
[ 
--- 73286 sleep 120
]
Scheduling escalation to SIGKILL in 3secs from now
[  FAILED  ] HealthCheckTest.HealthStatusChange (1639 ms)
{noformat}

These lines
{noformat}
Received task health update, healthy: true
rm: /private/tmp/z1PbfH/rG7Gha: No such file or directory
../../../src/tests/health_check_tests.cpp:790: Failure
{noformat}
obviously hint that we've queried the HTTP endpoint _after_ the next health status change.

> HealthCheckTest.HealthStatusChange is flaky on jenkins.
> -------------------------------------------------------
>
>                 Key: MESOS-1802
>                 URL: https://issues.apache.org/jira/browse/MESOS-1802
>             Project: Mesos
>          Issue Type: Bug
>          Components: test, tests
>    Affects Versions: 0.26.0
>            Reporter: Benjamin Mahler
>            Assignee: haosdent
>              Labels: flaky, health-check, mesosphere
>         Attachments: health_check_flaky_test_log.txt
>
>
> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2374/consoleFull
> {noformat}
> [ RUN      ] HealthCheckTest.HealthStatusChange
> Using temporary directory '/tmp/HealthCheckTest_HealthStatusChange_IYnlu2'
> I0916 22:56:14.034612 21026 leveldb.cpp:176] Opened db in 2.155713ms
> I0916 22:56:14.034965 21026 leveldb.cpp:183] Compacted db in 332489ns
> I0916 22:56:14.034984 21026 leveldb.cpp:198] Created db iterator in 3710ns
> I0916 22:56:14.034996 21026 leveldb.cpp:204] Seeked to beginning of db in 642ns
> I0916 22:56:14.035006 21026 leveldb.cpp:273] Iterated through 0 keys in the db in 343ns
> I0916 22:56:14.035023 21026 replica.cpp:741] Replica recovered with log positions 0 ->
0 with 1 holes and 0 unlearned
> I0916 22:56:14.035200 21054 recover.cpp:425] Starting replica recovery
> I0916 22:56:14.035403 21041 recover.cpp:451] Replica is in EMPTY status
> I0916 22:56:14.035888 21045 replica.cpp:638] Replica in EMPTY status received a broadcasted
recover request
> I0916 22:56:14.035969 21052 recover.cpp:188] Received a recover response from a replica
in EMPTY status
> I0916 22:56:14.036118 21042 recover.cpp:542] Updating replica status to STARTING
> I0916 22:56:14.036603 21046 master.cpp:286] Master 20140916-225614-3125920579-47865-21026
(penates.apache.org) started on 67.195.81.186:47865
> I0916 22:56:14.036634 21046 master.cpp:332] Master only allowing authenticated frameworks
to register
> I0916 22:56:14.036648 21046 master.cpp:337] Master only allowing authenticated slaves
to register
> I0916 22:56:14.036659 21046 credentials.hpp:36] Loading credentials for authentication
from '/tmp/HealthCheckTest_HealthStatusChange_IYnlu2/credentials'
> I0916 22:56:14.036686 21045 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb
took 480322ns
> I0916 22:56:14.036700 21045 replica.cpp:320] Persisted replica status to STARTING
> I0916 22:56:14.036769 21046 master.cpp:366] Authorization enabled
> I0916 22:56:14.036826 21045 recover.cpp:451] Replica is in STARTING status
> I0916 22:56:14.036944 21052 master.cpp:120] No whitelist given. Advertising offers for
all slaves
> I0916 22:56:14.036968 21049 hierarchical_allocator_process.hpp:299] Initializing hierarchical
allocator process with master : master@67.195.81.186:47865
> I0916 22:56:14.037284 21054 replica.cpp:638] Replica in STARTING status received a broadcasted
recover request
> I0916 22:56:14.037312 21046 master.cpp:1212] The newly elected leader is master@67.195.81.186:47865
with id 20140916-225614-3125920579-47865-21026
> I0916 22:56:14.037333 21046 master.cpp:1225] Elected as the leading master!
> I0916 22:56:14.037345 21046 master.cpp:1043] Recovering from registrar
> I0916 22:56:14.037504 21040 registrar.cpp:313] Recovering registrar
> I0916 22:56:14.037505 21053 recover.cpp:188] Received a recover response from a replica
in STARTING status
> I0916 22:56:14.037681 21047 recover.cpp:542] Updating replica status to VOTING
> I0916 22:56:14.038072 21052 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb
took 330251ns
> I0916 22:56:14.038087 21052 replica.cpp:320] Persisted replica status to VOTING
> I0916 22:56:14.038127 21053 recover.cpp:556] Successfully joined the Paxos group
> I0916 22:56:14.038202 21053 recover.cpp:440] Recover process terminated
> I0916 22:56:14.038364 21048 log.cpp:656] Attempting to start the writer
> I0916 22:56:14.038812 21053 replica.cpp:474] Replica received implicit promise request
with proposal 1
> I0916 22:56:14.038925 21053 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb
took 92623ns
> I0916 22:56:14.038944 21053 replica.cpp:342] Persisted promised to 1
> I0916 22:56:14.039201 21052 coordinator.cpp:230] Coordinator attemping to fill missing
position
> I0916 22:56:14.039676 21047 replica.cpp:375] Replica received explicit promise request
for position 0 with proposal 2
> I0916 22:56:14.039836 21047 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took
144215ns
> I0916 22:56:14.039850 21047 replica.cpp:676] Persisted action at 0
> I0916 22:56:14.040243 21047 replica.cpp:508] Replica received write request for position
0
> I0916 22:56:14.040267 21047 leveldb.cpp:438] Reading position from leveldb took 10323ns
> I0916 22:56:14.040362 21047 leveldb.cpp:343] Persisting action (14 bytes) to leveldb
took 79471ns
> I0916 22:56:14.040375 21047 replica.cpp:676] Persisted action at 0
> I0916 22:56:14.040556 21054 replica.cpp:655] Replica received learned notice for position
0
> I0916 22:56:14.040658 21054 leveldb.cpp:343] Persisting action (16 bytes) to leveldb
took 83975ns
> I0916 22:56:14.040676 21054 replica.cpp:676] Persisted action at 0
> I0916 22:56:14.040689 21054 replica.cpp:661] Replica learned NOP action at position 0
> I0916 22:56:14.041023 21043 log.cpp:672] Writer started with ending position 0
> I0916 22:56:14.041342 21052 leveldb.cpp:438] Reading position from leveldb took 10642ns
> I0916 22:56:14.042325 21050 registrar.cpp:346] Successfully fetched the registry (0B)
> I0916 22:56:14.042346 21050 registrar.cpp:422] Attempting to update the 'registry'
> I0916 22:56:14.043306 21054 log.cpp:680] Attempting to append 140 bytes to the log
> I0916 22:56:14.043354 21050 coordinator.cpp:340] Coordinator attempting to write APPEND
action at position 1
> I0916 22:56:14.043637 21047 replica.cpp:508] Replica received write request for position
1
> I0916 22:56:14.044042 21047 leveldb.cpp:343] Persisting action (159 bytes) to leveldb
took 386690ns
> I0916 22:56:14.044057 21047 replica.cpp:676] Persisted action at 1
> I0916 22:56:14.044271 21040 replica.cpp:655] Replica received learned notice for position
1
> I0916 22:56:14.044435 21040 leveldb.cpp:343] Persisting action (161 bytes) to leveldb
took 145186ns
> I0916 22:56:14.044448 21040 replica.cpp:676] Persisted action at 1
> I0916 22:56:14.044456 21040 replica.cpp:661] Replica learned APPEND action at position
1
> I0916 22:56:14.044729 21055 registrar.cpp:479] Successfully updated 'registry'
> I0916 22:56:14.044776 21047 log.cpp:699] Attempting to truncate the log to 1
> I0916 22:56:14.044795 21055 registrar.cpp:372] Successfully recovered registrar
> I0916 22:56:14.044831 21051 coordinator.cpp:340] Coordinator attempting to write TRUNCATE
action at position 2
> I0916 22:56:14.044899 21053 master.cpp:1070] Recovered 0 slaves from the Registry (102B)
; allowing 10mins for slaves to re-register
> I0916 22:56:14.045133 21055 replica.cpp:508] Replica received write request for position
2
> I0916 22:56:14.045450 21055 leveldb.cpp:343] Persisting action (16 bytes) to leveldb
took 300867ns
> I0916 22:56:14.045465 21055 replica.cpp:676] Persisted action at 2
> I0916 22:56:14.045725 21052 replica.cpp:655] Replica received learned notice for position
2
> I0916 22:56:14.045925 21052 leveldb.cpp:343] Persisting action (18 bytes) to leveldb
took 182657ns
> I0916 22:56:14.045948 21052 leveldb.cpp:401] Deleting ~1 keys from leveldb took 10733ns
> I0916 22:56:14.045958 21052 replica.cpp:676] Persisted action at 2
> I0916 22:56:14.045964 21052 replica.cpp:661] Replica learned TRUNCATE action at position
2
> I0916 22:56:14.055306 21026 containerizer.cpp:89] Using isolation: posix/cpu,posix/mem
> I0916 22:56:14.057139 21048 slave.cpp:169] Slave started on 102)@67.195.81.186:47865
> I0916 22:56:14.057178 21048 credentials.hpp:84] Loading credential for authentication
from '/tmp/HealthCheckTest_HealthStatusChange_cGKTiG/credential'
> I0916 22:56:14.057283 21048 slave.cpp:276] Slave using credential for: test-principal
> I0916 22:56:14.057354 21048 slave.cpp:289] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024;
ports(*):[31000-32000]
> I0916 22:56:14.057457 21048 slave.cpp:317] Slave hostname: penates.apache.org
> I0916 22:56:14.057468 21048 slave.cpp:318] Slave checkpoint: false
> I0916 22:56:14.057754 21043 state.cpp:33] Recovering state from '/tmp/HealthCheckTest_HealthStatusChange_cGKTiG/meta'
> I0916 22:56:14.057864 21042 status_update_manager.cpp:193] Recovering status update manager
> I0916 22:56:14.057958 21042 containerizer.cpp:252] Recovering containerizer
> I0916 22:56:14.058226 21042 slave.cpp:3219] Finished recovery
> I0916 22:56:14.058452 21047 slave.cpp:600] New master detected at master@67.195.81.186:47865
> I0916 22:56:14.058485 21047 slave.cpp:674] Authenticating with master master@67.195.81.186:47865
> I0916 22:56:14.058506 21042 status_update_manager.cpp:167] New master detected at master@67.195.81.186:47865
> I0916 22:56:14.058539 21047 slave.cpp:647] Detecting new master
> I0916 22:56:14.058555 21042 authenticatee.hpp:128] Creating new client SASL connection
> I0916 22:56:14.058656 21043 master.cpp:3653] Authenticating slave(102)@67.195.81.186:47865
> I0916 22:56:14.058737 21040 authenticator.hpp:156] Creating new server SASL connection
> I0916 22:56:14.058830 21047 authenticatee.hpp:219] Received SASL authentication mechanisms:
CRAM-MD5
> I0916 22:56:14.058852 21047 authenticatee.hpp:245] Attempting to authenticate with mechanism
'CRAM-MD5'
> I0916 22:56:14.058884 21047 authenticator.hpp:262] Received SASL authentication start
> I0916 22:56:14.058936 21047 authenticator.hpp:384] Authentication requires more steps
> I0916 22:56:14.058981 21047 authenticatee.hpp:265] Received SASL authentication step
> I0916 22:56:14.059052 21040 authenticator.hpp:290] Received SASL authentication step
> I0916 22:56:14.059074 21040 auxprop.cpp:81] Request to lookup properties for user: 'test-principal'
realm: 'penates.apache.org' server FQDN: 'penates.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
> I0916 22:56:14.059087 21040 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
> I0916 22:56:14.059101 21040 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> I0916 22:56:14.059111 21040 auxprop.cpp:81] Request to lookup properties for user: 'test-principal'
realm: 'penates.apache.org' server FQDN: 'penates.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
> I0916 22:56:14.059118 21040 auxprop.cpp:103] Skipping auxiliary property '*userPassword'
since SASL_AUXPROP_AUTHZID == true
> I0916 22:56:14.059123 21040 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5'
since SASL_AUXPROP_AUTHZID == true
> I0916 22:56:14.059135 21040 authenticator.hpp:376] Authentication success
> I0916 22:56:14.059182 21047 authenticatee.hpp:305] Authentication success
> I0916 22:56:14.059192 21040 master.cpp:3693] Successfully authenticated principal 'test-principal'
at slave(102)@67.195.81.186:47865
> I0916 22:56:14.059309 21047 slave.cpp:731] Successfully authenticated with master master@67.195.81.186:47865
> I0916 22:56:14.059348 21047 slave.cpp:994] Will retry registration in 12.6149ms if necessary
> I0916 22:56:14.059396 21040 master.cpp:2843] Registering slave at slave(102)@67.195.81.186:47865
(penates.apache.org) with id 20140916-225614-3125920579-47865-21026-0
> I0916 22:56:14.059495 21054 registrar.cpp:422] Attempting to update the 'registry'
> I0916 22:56:14.059558 21026 sched.cpp:137] Version: 0.21.0
> I0916 22:56:14.059710 21041 sched.cpp:233] New master detected at master@67.195.81.186:47865
> I0916 22:56:14.059730 21041 sched.cpp:283] Authenticating with master master@67.195.81.186:47865
> I0916 22:56:14.059788 21052 authenticatee.hpp:128] Creating new client SASL connection
> I0916 22:56:14.059890 21043 master.cpp:3653] Authenticating scheduler-59427aee-c9d1-45c7-96fc-12d0d48529a4@67.195.81.186:47865
> I0916 22:56:14.059960 21055 authenticator.hpp:156] Creating new server SASL connection
> I0916 22:56:14.060039 21040 authenticatee.hpp:219] Received SASL authentication mechanisms:
CRAM-MD5
> I0916 22:56:14.060061 21040 authenticatee.hpp:245] Attempting to authenticate with mechanism
'CRAM-MD5'
> I0916 22:56:14.060107 21055 authenticator.hpp:262] Received SASL authentication start
> I0916 22:56:14.060158 21055 authenticator.hpp:384] Authentication requires more steps
> I0916 22:56:14.060189 21055 authenticatee.hpp:265] Received SASL authentication step
> I0916 22:56:14.060220 21055 authenticator.hpp:290] Received SASL authentication step
> I0916 22:56:14.060236 21055 auxprop.cpp:81] Request to lookup properties for user: 'test-principal'
realm: 'penates.apache.org' server FQDN: 'penates.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
> I0916 22:56:14.060250 21055 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
> I0916 22:56:14.060277 21055 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> I0916 22:56:14.060288 21055 auxprop.cpp:81] Request to lookup properties for user: 'test-principal'
realm: 'penates.apache.org' server FQDN: 'penates.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
> I0916 22:56:14.060295 21055 auxprop.cpp:103] Skipping auxiliary property '*userPassword'
since SASL_AUXPROP_AUTHZID == true
> I0916 22:56:14.060300 21055 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5'
since SASL_AUXPROP_AUTHZID == true
> I0916 22:56:14.060312 21055 authenticator.hpp:376] Authentication success
> I0916 22:56:14.060349 21040 authenticatee.hpp:305] Authentication success
> I0916 22:56:14.060364 21055 master.cpp:3693] Successfully authenticated principal 'test-principal'
at scheduler-59427aee-c9d1-45c7-96fc-12d0d48529a4@67.195.81.186:47865
> I0916 22:56:14.060480 21046 sched.cpp:357] Successfully authenticated with master master@67.195.81.186:47865
> I0916 22:56:14.060499 21046 sched.cpp:476] Sending registration request to master@67.195.81.186:47865
> I0916 22:56:14.060564 21050 master.cpp:1331] Received registration request from scheduler-59427aee-c9d1-45c7-96fc-12d0d48529a4@67.195.81.186:47865
> I0916 22:56:14.060593 21050 master.cpp:1291] Authorizing framework principal 'test-principal'
to receive offers for role '*'
> I0916 22:56:14.060767 21053 master.cpp:1390] Registering framework 20140916-225614-3125920579-47865-21026-0000
at scheduler-59427aee-c9d1-45c7-96fc-12d0d48529a4@67.195.81.186:47865
> I0916 22:56:14.060797 21049 log.cpp:680] Attempting to append 337 bytes to the log
> I0916 22:56:14.060873 21042 hierarchical_allocator_process.hpp:329] Added framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:14.060873 21040 coordinator.cpp:340] Coordinator attempting to write APPEND
action at position 3
> I0916 22:56:14.060899 21042 hierarchical_allocator_process.hpp:697] No resources available
to allocate!
> I0916 22:56:14.060909 21042 hierarchical_allocator_process.hpp:659] Performed allocation
for 0 slaves in 11862ns
> I0916 22:56:14.061061 21044 sched.cpp:407] Framework registered with 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:14.061115 21044 sched.cpp:421] Scheduler::registered took 34395ns
> I0916 22:56:14.061173 21047 replica.cpp:508] Replica received write request for position
3
> I0916 22:56:14.061298 21047 leveldb.cpp:343] Persisting action (356 bytes) to leveldb
took 108843ns
> I0916 22:56:14.061311 21047 replica.cpp:676] Persisted action at 3
> I0916 22:56:14.061553 21049 replica.cpp:655] Replica received learned notice for position
3
> I0916 22:56:14.061965 21049 leveldb.cpp:343] Persisting action (358 bytes) to leveldb
took 392670ns
> I0916 22:56:14.061985 21049 replica.cpp:676] Persisted action at 3
> I0916 22:56:14.061996 21049 replica.cpp:661] Replica learned APPEND action at position
3
> I0916 22:56:14.062268 21050 registrar.cpp:479] Successfully updated 'registry'
> I0916 22:56:14.062331 21051 log.cpp:699] Attempting to truncate the log to 3
> I0916 22:56:14.062355 21040 master.cpp:2883] Registered slave 20140916-225614-3125920579-47865-21026-0
at slave(102)@67.195.81.186:47865 (penates.apache.org)
> I0916 22:56:14.062386 21043 coordinator.cpp:340] Coordinator attempting to write TRUNCATE
action at position 4
> I0916 22:56:14.062376 21040 master.cpp:4126] Adding slave 20140916-225614-3125920579-47865-21026-0
at slave(102)@67.195.81.186:47865 (penates.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024;
ports(*):[31000-32000]
> I0916 22:56:14.062510 21045 slave.cpp:765] Registered with master master@67.195.81.186:47865;
given slave ID 20140916-225614-3125920579-47865-21026-0
> I0916 22:56:14.062573 21045 slave.cpp:2346] Received ping from slave-observer(98)@67.195.81.186:47865
> I0916 22:56:14.062599 21049 hierarchical_allocator_process.hpp:442] Added slave 20140916-225614-3125920579-47865-21026-0
(penates.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and
cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
> I0916 22:56:14.062669 21049 hierarchical_allocator_process.hpp:734] Offering cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140916-225614-3125920579-47865-21026-0
to framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:14.062764 21041 replica.cpp:508] Replica received write request for position
4
> I0916 22:56:14.062788 21049 hierarchical_allocator_process.hpp:679] Performed allocation
for slave 20140916-225614-3125920579-47865-21026-0 in 145691ns
> I0916 22:56:14.062839 21050 master.hpp:861] Adding offer 20140916-225614-3125920579-47865-21026-0
with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140916-225614-3125920579-47865-21026-0
(penates.apache.org)
> I0916 22:56:14.062891 21041 leveldb.cpp:343] Persisting action (16 bytes) to leveldb
took 110169ns
> I0916 22:56:14.062907 21041 replica.cpp:676] Persisted action at 4
> I0916 22:56:14.062911 21050 master.cpp:3600] Sending 1 offers to framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:14.063065 21043 sched.cpp:544] Scheduler::resourceOffers took 39808ns
> I0916 22:56:14.063163 21046 replica.cpp:655] Replica received learned notice for position
4
> I0916 22:56:14.063272 21046 leveldb.cpp:343] Persisting action (18 bytes) to leveldb
took 89981ns
> I0916 22:56:14.063308 21046 leveldb.cpp:401] Deleting ~2 keys from leveldb took 18542ns
> I0916 22:56:14.063323 21046 replica.cpp:676] Persisted action at 4
> I0916 22:56:14.063333 21046 replica.cpp:661] Replica learned TRUNCATE action at position
4
> I0916 22:56:14.063482 21044 master.hpp:871] Removing offer 20140916-225614-3125920579-47865-21026-0
with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140916-225614-3125920579-47865-21026-0
(penates.apache.org)
> I0916 22:56:14.063535 21044 master.cpp:2201] Processing reply for offers: [ 20140916-225614-3125920579-47865-21026-0
] on slave 20140916-225614-3125920579-47865-21026-0 at slave(102)@67.195.81.186:47865 (penates.apache.org)
for framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:14.063561 21044 master.cpp:2284] Authorizing framework principal 'test-principal'
to launch task 1 as user 'jenkins'
> I0916 22:56:14.063824 21040 master.hpp:833] Adding task 1 with resources cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] on slave 20140916-225614-3125920579-47865-21026-0 (penates.apache.org)
> I0916 22:56:14.063860 21040 master.cpp:2350] Launching task 1 of framework 20140916-225614-3125920579-47865-21026-0000
with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140916-225614-3125920579-47865-21026-0
at slave(102)@67.195.81.186:47865 (penates.apache.org)
> I0916 22:56:14.063943 21050 slave.cpp:1025] Got assigned task 1 for framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:14.064158 21050 slave.cpp:1135] Launching task 1 for framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:14.065439 21050 slave.cpp:1248] Queuing task '1' for executor 1 of framework
'20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:14.065460 21041 containerizer.cpp:394] Starting container 'd383a013-89cf-47c6-ad8e-39e2f3e971fd'
for executor '1' of framework '20140916-225614-3125920579-47865-21026-0000'
> I0916 22:56:14.065477 21050 slave.cpp:554] Successfully attached file '/tmp/HealthCheckTest_HealthStatusChange_cGKTiG/slaves/20140916-225614-3125920579-47865-21026-0/frameworks/20140916-225614-3125920579-47865-21026-0000/executors/1/runs/d383a013-89cf-47c6-ad8e-39e2f3e971fd'
> I0916 22:56:14.066735 21055 launcher.cpp:137] Forked child with pid '21858' for container
'd383a013-89cf-47c6-ad8e-39e2f3e971fd'
> I0916 22:56:14.067486 21044 containerizer.cpp:510] Fetching URIs for container 'd383a013-89cf-47c6-ad8e-39e2f3e971fd'
using command '/home/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src/mesos-fetcher'
> I0916 22:56:15.037449 21050 hierarchical_allocator_process.hpp:659] Performed allocation
for 1 slaves in 43708ns
> I0916 22:56:15.038743 21054 slave.cpp:2559] Monitoring executor '1' of framework '20140916-225614-3125920579-47865-21026-0000'
in container 'd383a013-89cf-47c6-ad8e-39e2f3e971fd'
> I0916 22:56:15.078441 21053 slave.cpp:1758] Got registration for executor '1' of framework
20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:15.078866 21053 slave.cpp:1876] Flushing queued task 1 for executor '1' of
framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:15.084800 21043 slave.cpp:2110] Handling status update TASK_RUNNING (UUID:
a16d2819-e9f4-4119-bde6-f00ad33033e5) for task 1 of framework 20140916-225614-3125920579-47865-21026-0000
from executor(1)@67.195.81.186:35510
> I0916 22:56:15.084969 21041 status_update_manager.cpp:320] Received status update TASK_RUNNING
(UUID: a16d2819-e9f4-4119-bde6-f00ad33033e5) for task 1 of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:15.084995 21041 status_update_manager.cpp:499] Creating StatusUpdate stream
for task 1 of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:15.085160 21041 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING
(UUID: a16d2819-e9f4-4119-bde6-f00ad33033e5) for task 1 of framework 20140916-225614-3125920579-47865-21026-0000
to master@67.195.81.186:47865
> I0916 22:56:15.085314 21043 slave.cpp:2267] Status update manager successfully handled
status update TASK_RUNNING (UUID: a16d2819-e9f4-4119-bde6-f00ad33033e5) for task 1 of framework
20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:15.085332 21041 master.cpp:3212] Forwarding status update TASK_RUNNING (UUID:
a16d2819-e9f4-4119-bde6-f00ad33033e5) for task 1 of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:15.085335 21043 slave.cpp:2273] Sending acknowledgement for status update
TASK_RUNNING (UUID: a16d2819-e9f4-4119-bde6-f00ad33033e5) for task 1 of framework 20140916-225614-3125920579-47865-21026-0000
to executor(1)@67.195.81.186:35510
> I0916 22:56:15.085435 21041 master.cpp:3178] Status update TASK_RUNNING (UUID: a16d2819-e9f4-4119-bde6-f00ad33033e5)
for task 1 of framework 20140916-225614-3125920579-47865-21026-0000 from slave 20140916-225614-3125920579-47865-21026-0
at slave(102)@67.195.81.186:47865 (penates.apache.org)
> I0916 22:56:15.085675 21044 sched.cpp:635] Scheduler::statusUpdate took 113998ns
> I0916 22:56:15.085888 21052 master.cpp:2693] Forwarding status update acknowledgement
a16d2819-e9f4-4119-bde6-f00ad33033e5 for task 1 of framework 20140916-225614-3125920579-47865-21026-0000
to slave 20140916-225614-3125920579-47865-21026-0 at slave(102)@67.195.81.186:47865 (penates.apache.org)
> I0916 22:56:15.086109 21051 status_update_manager.cpp:398] Received status update acknowledgement
(UUID: a16d2819-e9f4-4119-bde6-f00ad33033e5) for task 1 of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:15.086205 21051 slave.cpp:1698] Status update manager successfully handled
status update acknowledgement (UUID: a16d2819-e9f4-4119-bde6-f00ad33033e5) for task 1 of framework
20140916-225614-3125920579-47865-21026-0000
> I../../src/tests/health_check_tests.cpp:330: Failure
> Failed to wait 10secs for statusHealth1
> 0916 22:56:16.038705 21049 hierarchical_allocator_process.hpp:659] Performed allocation
for 1 slaves in 40061ns
> I0916 22:56:16.126260 21052 slave.cpp:2110] Handling status update TASK_RUNNING (UUID:
792b8e42-0d72-451b-978a-7d1f29a15751) for task 1 in health state healthy of framework 20140916-225614-3125920579-47865-21026-0000
from executor(1)@67.195.81.186:35510
> I0916 22:56:28.190274 21045 master.cpp:741] Framework 20140916-225614-3125920579-47865-21026-0000
disconnected
> I0916 22:56:28.190304 21045 master.cpp:1687] Deactivating framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:19.037235 21050 master.cpp:120] No whitelist given. Advertising offers for
all slaves
> I0916 22:56:28.190394 21045 master.cpp:763] Giving framework 20140916-225614-3125920579-47865-21026-0000
0ns to failover
> ../../src/tests/health_check_tests.cpp:319: Failure
> Actual function call count doesn't match EXPECT_CALL(sched, statusUpdate(&driver,
_))...
>          Expected: to be called 4 times
>            Actual: called once - unsatisfied and active
> I0916 22:56:28.190624 21052 slave.cpp:2110] Handling status update TASK_RUNNING (UUID:
5783bb6f-112f-4434-a160-a336e890398a) for task 1 in health state unhealthy of framework 20140916-225614-3125920579-47865-21026-0000
from executor(1)@67.195.81.186:35510
> I0916 22:56:28.190757 21052 slave.cpp:2110] Handling status update TASK_RUNNING (UUID:
b4a9f647-3894-47f3-b55e-49d0355b20f9) for task 1 in health state healthy of framework 20140916-225614-3125920579-47865-21026-0000
from executor(1)@67.195.81.186:35510
> I0916 22:56:28.190773 21046 status_update_manager.cpp:320] Received status update TASK_RUNNING
(UUID: 792b8e42-0d72-451b-978a-7d1f29a15751) for task 1 in health state healthy of framework
20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.190831 21040 hierarchical_allocator_process.hpp:405] Deactivated framework
20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.190856 21054 master.cpp:3471] Framework failover timeout, removing framework
20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.190846 21046 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING
(UUID: 792b8e42-0d72-451b-978a-7d1f29a15751) for task 1 in health state healthy of framework
20140916-225614-3125920579-47865-21026-0000 to master@67.195.81.186:47865
> I0916 22:56:28.190887 21054 master.cpp:3976] Removing framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.190887 21052 slave.cpp:2110] Handling status update TASK_RUNNING (UUID:
b5d5d6c7-e92c-4ca0-ab72-656542c14ade) for task 1 in health state unhealthy of framework 20140916-225614-3125920579-47865-21026-0000
from executor(1)@67.195.81.186:35510
> I0916 22:56:28.190994 21052 slave.cpp:2110] Handling status update TASK_RUNNING (UUID:
c0225c5c-b15e-4b5e-a063-07a29703ea12) for task 1 in health state healthy of framework 20140916-225614-3125920579-47865-21026-0000
from executor(1)@67.195.81.186:35510
> I0916 22:56:28.190996 21046 status_update_manager.cpp:320] Received status update TASK_RUNNING
(UUID: 5783bb6f-112f-4434-a160-a336e890398a) for task 1 in health state unhealthy of framework
20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.190999 21054 master.hpp:851] Removing task 1 with resources cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140916-225614-3125920579-47865-21026-0
(penates.apache.org)
> I0916 22:56:28.191090 21046 status_update_manager.cpp:320] Received status update TASK_RUNNING
(UUID: b4a9f647-3894-47f3-b55e-49d0355b20f9) for task 1 in health state healthy of framework
20140916-225614-3125920579-47865-21026-0000
> W0916 22:56:28.191141 21054 master.cpp:4419] Removing task 1 of framework 20140916-225614-3125920579-47865-21026-0000
and slave 20140916-225614-3125920579-47865-21026-0 in non-terminal state TASK_RUNNING
> I0916 22:56:28.191093 21052 slave.cpp:2110] Handling status update TASK_RUNNING (UUID:
e9e3fdb1-d8e0-4bfc-970b-fcd098cace13) for task 1 in health state unhealthy of framework 20140916-225614-3125920579-47865-21026-0000
from executor(1)@67.195.81.186:35510
> I0916 22:56:28.191181 21046 status_update_manager.cpp:320] Received status update TASK_RUNNING
(UUID: b5d5d6c7-e92c-4ca0-ab72-656542c14ade) for task 1 in health state unhealthy of framework
20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.191256 21054 master.cpp:650] Master terminating
> I0916 22:56:28.191258 21043 hierarchical_allocator_process.hpp:563] Recovered cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total allocatable: cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000]) on slave 20140916-225614-3125920579-47865-21026-0 from
framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.369088 21046 status_update_manager.cpp:320] Received status update TASK_RUNNING
(UUID: c0225c5c-b15e-4b5e-a063-07a29703ea12) for task 1 in health state healthy of framework
20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.191319 21052 slave.cpp:2110] Handling status update TASK_RUNNING (UUID:
780d211b-6ecc-478d-93e9-6744ed0a2d33) for task 1 in health state healthy of framework 20140916-225614-3125920579-47865-21026-0000
from executor(1)@67.195.81.186:35510
> I0916 22:56:28.369132 21043 hierarchical_allocator_process.hpp:360] Removed framework
20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.369225 21046 status_update_manager.cpp:320] Received status update TASK_RUNNING
(UUID: e9e3fdb1-d8e0-4bfc-970b-fcd098cace13) for task 1 in health state unhealthy of framework
20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.369283 21052 slave.cpp:2110] Handling status update TASK_RUNNING (UUID:
f41475b5-9b45-478e-8cd9-2cf7854627dd) for task 1 in health state unhealthy of framework 20140916-225614-3125920579-47865-21026-0000
from executor(1)@67.195.81.186:35510
> I0916 22:56:28.369323 21046 status_update_manager.cpp:320] Received status update TASK_RUNNING
(UUID: 780d211b-6ecc-478d-93e9-6744ed0a2d33) for task 1 in health state healthy of framework
20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.369415 21046 status_update_manager.cpp:320] Received status update TASK_RUNNING
(UUID: f41475b5-9b45-478e-8cd9-2cf7854627dd) for task 1 in health state unhealthy of framework
20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.369420 21052 slave.cpp:2110] Handling status update TASK_RUNNING (UUID:
5f3a1b44-51f0-4deb-ba4c-e7238f63f856) for task 1 in health state healthy of framework 20140916-225614-3125920579-47865-21026-0000
from executor(1)@67.195.81.186:35510
> I0916 22:56:28.369536 21052 slave.cpp:2110] Handling status update TASK_RUNNING (UUID:
4663a09b-147f-455c-a577-3d967ddf5256) for task 1 in health state unhealthy of framework 20140916-225614-3125920579-47865-21026-0000
from executor(1)@67.195.81.186:35510
> I0916 22:56:28.369642 21052 slave.cpp:2110] Handling status update TASK_RUNNING (UUID:
89cbabd7-0169-4b58-8df7-d8fd4bc4a287) for task 1 in health state healthy of framework 20140916-225614-3125920579-47865-21026-0000
from executor(1)@67.195.81.186:35510
> I0916 22:56:28.369685 21055 status_update_manager.cpp:320] Received status update TASK_RUNNING
(UUID: 5f3a1b44-51f0-4deb-ba4c-e7238f63f856) for task 1 in health state healthy of framework
20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.369753 21052 slave.cpp:2110] Handling status update TASK_RUNNING (UUID:
3c491f72-95f1-4c52-b7ca-c6470f748eb5) for task 1 in health state unhealthy of framework 20140916-225614-3125920579-47865-21026-0000
from executor(1)@67.195.81.186:35510
> I0916 22:56:28.369802 21055 status_update_manager.cpp:320] Received status update TASK_RUNNING
(UUID: 4663a09b-147f-455c-a577-3d967ddf5256) for task 1 in health state unhealthy of framework
20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.369884 21055 status_update_manager.cpp:320] Received status update TASK_RUNNING
(UUID: 89cbabd7-0169-4b58-8df7-d8fd4bc4a287) for task 1 in health state healthy of framework
20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.369889 21052 slave.cpp:2110] Handling status update TASK_RUNNING (UUID:
218be9bd-a229-4808-8fb6-1e507830cdaf) for task 1 in health state healthy of framework 20140916-225614-3125920579-47865-21026-0000
from executor(1)@67.195.81.186:35510
> I0916 22:56:28.369943 21055 status_update_manager.cpp:320] Received status update TASK_RUNNING
(UUID: 3c491f72-95f1-4c52-b7ca-c6470f748eb5) for task 1 in health state unhealthy of framework
20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.369978 21052 slave.cpp:1431] Asked to shut down framework 20140916-225614-3125920579-47865-21026-0000
by master@67.195.81.186:47865
> I0916 22:56:28.369998 21052 slave.cpp:1456] Shutting down framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.370009 21055 status_update_manager.cpp:320] Received status update TASK_RUNNING
(UUID: 218be9bd-a229-4808-8fb6-1e507830cdaf) for task 1 in health state healthy of framework
20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.370018 21052 slave.cpp:2899] Shutting down executor '1' of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.370183 21052 slave.cpp:2267] Status update manager successfully handled
status update TASK_RUNNING (UUID: 792b8e42-0d72-451b-978a-7d1f29a15751) for task 1 in health
state healthy of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.370206 21052 slave.cpp:2273] Sending acknowledgement for status update
TASK_RUNNING (UUID: 792b8e42-0d72-451b-978a-7d1f29a15751) for task 1 in health state healthy
of framework 20140916-225614-3125920579-47865-21026-0000 to executor(1)@67.195.81.186:35510
> I0916 22:56:28.370426 21052 slave.cpp:2267] Status update manager successfully handled
status update TASK_RUNNING (UUID: 5783bb6f-112f-4434-a160-a336e890398a) for task 1 in health
state unhealthy of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.370447 21052 slave.cpp:2273] Sending acknowledgement for status update
TASK_RUNNING (UUID: 5783bb6f-112f-4434-a160-a336e890398a) for task 1 in health state unhealthy
of framework 20140916-225614-3125920579-47865-21026-0000 to executor(1)@67.195.81.186:35510
> I0916 22:56:28.370635 21052 slave.cpp:2267] Status update manager successfully handled
status update TASK_RUNNING (UUID: b4a9f647-3894-47f3-b55e-49d0355b20f9) for task 1 in health
state healthy of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.370657 21052 slave.cpp:2273] Sending acknowledgement for status update
TASK_RUNNING (UUID: b4a9f647-3894-47f3-b55e-49d0355b20f9) for task 1 in health state healthy
of framework 20140916-225614-3125920579-47865-21026-0000 to executor(1)@67.195.81.186:35510
> I0916 22:56:28.370815 21052 slave.cpp:2267] Status update manager successfully handled
status update TASK_RUNNING (UUID: b5d5d6c7-e92c-4ca0-ab72-656542c14ade) for task 1 in health
state unhealthy of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.370837 21052 slave.cpp:2273] Sending acknowledgement for status update
TASK_RUNNING (UUID: b5d5d6c7-e92c-4ca0-ab72-656542c14ade) for task 1 in health state unhealthy
of framework 20140916-225614-3125920579-47865-21026-0000 to executor(1)@67.195.81.186:35510
> I0916 22:56:28.370972 21052 slave.cpp:2267] Status update manager successfully handled
status update TASK_RUNNING (UUID: c0225c5c-b15e-4b5e-a063-07a29703ea12) for task 1 in health
state healthy of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.371000 21052 slave.cpp:2273] Sending acknowledgement for status update
TASK_RUNNING (UUID: c0225c5c-b15e-4b5e-a063-07a29703ea12) for task 1 in health state healthy
of framework 20140916-225614-3125920579-47865-21026-0000 to executor(1)@67.195.81.186:35510
> I0916 22:56:28.371155 21052 slave.cpp:2378] master@67.195.81.186:47865 exited
> W0916 22:56:28.371177 21052 slave.cpp:2381] Master disconnected! Waiting for a new master
to be elected
> I0916 22:56:28.371202 21052 slave.cpp:2267] Status update manager successfully handled
status update TASK_RUNNING (UUID: e9e3fdb1-d8e0-4bfc-970b-fcd098cace13) for task 1 in health
state unhealthy of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.540035 21052 slave.cpp:2273] Sending acknowledgement for status update
TASK_RUNNING (UUID: e9e3fdb1-d8e0-4bfc-970b-fcd098cace13) for task 1 in health state unhealthy
of framework 20140916-225614-3125920579-47865-21026-0000 to executor(1)@67.195.81.186:35510
> I0916 22:56:28.371701 21053 containerizer.cpp:882] Destroying container 'd383a013-89cf-47c6-ad8e-39e2f3e971fd'
> I0916 22:56:28.540177 21052 slave.cpp:2267] Status update manager successfully handled
status update TASK_RUNNING (UUID: 780d211b-6ecc-478d-93e9-6744ed0a2d33) for task 1 in health
state healthy of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.540196 21052 slave.cpp:2273] Sending acknowledgement for status update
TASK_RUNNING (UUID: 780d211b-6ecc-478d-93e9-6744ed0a2d33) for task 1 in health state healthy
of framework 20140916-225614-3125920579-47865-21026-0000 to executor(1)@67.195.81.186:35510
> I0916 22:56:28.540324 21052 slave.cpp:2267] Status update manager successfully handled
status update TASK_RUNNING (UUID: f41475b5-9b45-478e-8cd9-2cf7854627dd) for task 1 in health
state unhealthy of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.540350 21052 slave.cpp:2273] Sending acknowledgement for status update
TASK_RUNNING (UUID: f41475b5-9b45-478e-8cd9-2cf7854627dd) for task 1 in health state unhealthy
of framework 20140916-225614-3125920579-47865-21026-0000 to executor(1)@67.195.81.186:35510
> I0916 22:56:28.540403 21052 slave.cpp:2267] Status update manager successfully handled
status update TASK_RUNNING (UUID: 5f3a1b44-51f0-4deb-ba4c-e7238f63f856) for task 1 in health
state healthy of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.540421 21052 slave.cpp:2273] Sending acknowledgement for status update
TASK_RUNNING (UUID: 5f3a1b44-51f0-4deb-ba4c-e7238f63f856) for task 1 in health state healthy
of framework 20140916-225614-3125920579-47865-21026-0000 to executor(1)@67.195.81.186:35510
> I0916 22:56:28.540530 21052 slave.cpp:2267] Status update manager successfully handled
status update TASK_RUNNING (UUID: 4663a09b-147f-455c-a577-3d967ddf5256) for task 1 in health
state unhealthy of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.540556 21052 slave.cpp:2273] Sending acknowledgement for status update
TASK_RUNNING (UUID: 4663a09b-147f-455c-a577-3d967ddf5256) for task 1 in health state unhealthy
of framework 20140916-225614-3125920579-47865-21026-0000 to executor(1)@67.195.81.186:35510
> I0916 22:56:28.540664 21052 slave.cpp:2267] Status update manager successfully handled
status update TASK_RUNNING (UUID: 89cbabd7-0169-4b58-8df7-d8fd4bc4a287) for task 1 in health
state healthy of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.540681 21052 slave.cpp:2273] Sending acknowledgement for status update
TASK_RUNNING (UUID: 89cbabd7-0169-4b58-8df7-d8fd4bc4a287) for task 1 in health state healthy
of framework 20140916-225614-3125920579-47865-21026-0000 to executor(1)@67.195.81.186:35510
> I0916 22:56:28.540889 21052 slave.cpp:2267] Status update manager successfully handled
status update TASK_RUNNING (UUID: 3c491f72-95f1-4c52-b7ca-c6470f748eb5) for task 1 in health
state unhealthy of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.540918 21052 slave.cpp:2273] Sending acknowledgement for status update
TASK_RUNNING (UUID: 3c491f72-95f1-4c52-b7ca-c6470f748eb5) for task 1 in health state unhealthy
of framework 20140916-225614-3125920579-47865-21026-0000 to executor(1)@67.195.81.186:35510
> I0916 22:56:28.541082 21052 slave.cpp:2267] Status update manager successfully handled
status update TASK_RUNNING (UUID: 218be9bd-a229-4808-8fb6-1e507830cdaf) for task 1 in health
state healthy of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:28.541111 21052 slave.cpp:2273] Sending acknowledgement for status update
TASK_RUNNING (UUID: 218be9bd-a229-4808-8fb6-1e507830cdaf) for task 1 in health state healthy
of framework 20140916-225614-3125920579-47865-21026-0000 to executor(1)@67.195.81.186:35510
> I0916 22:56:29.047708 21053 containerizer.cpp:997] Executor for container 'd383a013-89cf-47c6-ad8e-39e2f3e971fd'
has exited
> I0916 22:56:29.048037 21050 slave.cpp:2617] Executor '1' of framework 20140916-225614-3125920579-47865-21026-0000
terminated with signal Killed
> I0916 22:56:29.048197 21050 slave.cpp:2753] Cleaning up executor '1' of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:29.048373 21050 slave.cpp:2828] Cleaning up framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:29.048444 21043 status_update_manager.cpp:282] Closing status update streams
for framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:29.048457 21050 slave.cpp:477] Slave terminating
> I0916 22:56:29.048476 21043 status_update_manager.cpp:530] Cleaning up status update
stream for task 1 of framework 20140916-225614-3125920579-47865-21026-0000
> I0916 22:56:29.048462 21041 gc.cpp:56] Scheduling '/tmp/HealthCheckTest_HealthStatusChange_cGKTiG/slaves/20140916-225614-3125920579-47865-21026-0/frameworks/20140916-225614-3125920579-47865-21026-0000/executors/1/runs/d383a013-89cf-47c6-ad8e-39e2f3e971fd'
for gc 6.99999944121481days in the future
> I0916 22:56:29.048568 21041 gc.cpp:56] Scheduling '/tmp/HealthCheckTest_HealthStatusChange_cGKTiG/slaves/20140916-225614-3125920579-47865-21026-0/frameworks/20140916-225614-3125920579-47865-21026-0000/executors/1'
for gc 6.99999944031111days in the future
> I0916 22:56:29.048607 21041 gc.cpp:56] Scheduling '/tmp/HealthCheckTest_HealthStatusChange_cGKTiG/slaves/20140916-225614-3125920579-47865-21026-0/frameworks/20140916-225614-3125920579-47865-21026-0000'
for gc 6.99999943939852days in the future
> [  FAILED  ] HealthCheckTest.HealthStatusChange (15019 ms)
> {noformat}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message