You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mesos.apache.org by "Benjamin Mahler (JIRA)" <ji...@apache.org> on 2013/11/06 02:50:17 UTC

[jira] [Resolved] (MESOS-801) SlaveRecoveryTest / ReconcileTasksMissingFromSlave is flaky.

     [ https://issues.apache.org/jira/browse/MESOS-801?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Benjamin Mahler resolved MESOS-801.
-----------------------------------

    Resolution: Fixed

Fix committed:

{noformat}
commit c5789a3e21d0916525677e98f18cbdab5c7f916b
Author: Benjamin Mahler <bm...@twitter.com>
Date:   Tue Nov 5 17:08:37 2013 -0800

    Fixed the flaky ReconcileTasksMissingFromSlave test.

    Review: https://reviews.apache.org/r/15254
{noformat}

> SlaveRecoveryTest / ReconcileTasksMissingFromSlave is flaky.
> ------------------------------------------------------------
>
>                 Key: MESOS-801
>                 URL: https://issues.apache.org/jira/browse/MESOS-801
>             Project: Mesos
>          Issue Type: Bug
>    Affects Versions: 0.16.0
>            Reporter: Benjamin Mahler
>            Assignee: Benjamin Mahler
>             Fix For: 0.16.0
>
>
> [ RUN      ] SlaveRecoveryTest/0.ReconcileTasksMissingFromSlave
> I1105 14:34:10.037295  6553 master.cpp:293] Master started on 127.0.0.1:48584
> I1105 14:34:10.037344  6553 master.cpp:308] Master ID: 201311051434-16777343-48584-6532
> I1105 14:34:10.037360  6553 master.cpp:311] Master only allowing authenticated frameworks to register!
> I1105 14:34:10.037737  6553 master.cpp:706] Elected as master!
> I1105 14:34:10.037901  6553 master.cpp:85] No whitelist given. Advertising offers for all slaves
> I1105 14:34:10.037940  6553 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : master@127.0.0.1:48584
> I1105 14:34:10.039150  6553 slave.cpp:109] Slave started on 37)@127.0.0.1:48584
> I1105 14:34:10.039232  6553 slave.cpp:209] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I1105 14:34:10.039582  6553 slave.cpp:488] New master detected at master@127.0.0.1:48584
> I1105 14:34:10.039607  6553 slave.cpp:503] Postponing registration until recovery is complete
> I1105 14:34:10.039655  6553 sched.cpp:199] New master at master@127.0.0.1:48584
> I1105 14:34:10.039669  6553 sched.cpp:285] Authenticating with master master@127.0.0.1:48584
> I1105 14:34:10.039800  6553 status_update_manager.cpp:158] New master detected at master@127.0.0.1:48584
> I1105 14:34:10.039821  6553 state.cpp:33] Recovering state from '/tmp/SlaveRecoveryTest_0_ReconcileTasksMissingFromSlave_Dcb21i/meta'
> I1105 14:34:10.039880  6553 authenticatee.hpp:124] Creating new client SASL connection
> I1105 14:34:10.039960  6553 master.cpp:1695] Authenticating framework at scheduler(26)@127.0.0.1:48584
> I1105 14:34:10.040014  6553 status_update_manager.cpp:180] Recovering status update manager
> I1105 14:34:10.040048  6553 authenticator.hpp:140] Creating new server SASL connection
> I1105 14:34:10.040089  6553 process_isolator.cpp:314] Recovering isolator
> I1105 14:34:10.040125  6553 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5
> I1105 14:34:10.040138  6553 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
> I1105 14:34:10.040163  6553 slave.cpp:2744] Finished recovery
> I1105 14:34:10.040233  6553 authenticator.hpp:243] Received SASL authentication start
> I1105 14:34:10.040277  6553 authenticator.hpp:325] Authentication requires more steps
> I1105 14:34:10.040318  6553 master.cpp:1232] Attempting to register slave on localhost.localdomain at slave(37)@127.0.0.1:48584
> I1105 14:34:10.040329  6553 master.cpp:2474] Adding slave 201311051434-16777343-48584-6532-0 at localhost.localdomain with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I1105 14:34:10.040401  6553 authenticatee.hpp:258] Received SASL authentication step
> I1105 14:34:10.040436  6553 slave.cpp:554] Registered with master master@127.0.0.1:48584; given slave ID 201311051434-16777343-48584-6532-0
> I1105 14:34:10.040624  6554 authenticator.hpp:271] Received SASL authentication step
> I1105 14:34:10.040649  6554 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'localhost.localdomain' server FQDN: 'localhost.localdomain' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
> I1105 14:34:10.040658  6554 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
> I1105 14:34:10.040668  6554 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> I1105 14:34:10.040678  6554 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'localhost.localdomain' server FQDN: 'localhost.localdomain' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
> I1105 14:34:10.040685  6554 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I1105 14:34:10.040691  6554 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I1105 14:34:10.040704  6554 authenticator.hpp:317] Authentication success
> I1105 14:34:10.040751  6554 hierarchical_allocator_process.hpp:445] Added slave 201311051434-16777343-48584-6532-0 (localhost.localdomain) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
> I1105 14:34:10.040786  6554 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201311051434-16777343-48584-6532-0 in 5851ns
> I1105 14:34:10.040803  6554 authenticatee.hpp:298] Authentication success
> I1105 14:34:10.040818  6554 master.cpp:1735] Successfully authenticated framework at scheduler(26)@127.0.0.1:48584
> I1105 14:34:10.040868  6554 sched.cpp:347] Successfully authenticated with master master@127.0.0.1:48584
> I1105 14:34:10.040902  6554 master.cpp:764] Received registration request from scheduler(26)@127.0.0.1:48584
> I1105 14:34:10.041007  6554 master.cpp:782] Registering framework 201311051434-16777343-48584-6532-0000 at scheduler(26)@127.0.0.1:48584
> I1105 14:34:10.041055  6554 sched.cpp:386] Framework registered with 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.041075  6554 sched.cpp:400] Scheduler::registered took 9458ns
> I1105 14:34:10.041108  6554 hierarchical_allocator_process.hpp:332] Added framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.041138  6554 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201311051434-16777343-48584-6532-0 to framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.041218  6554 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 97275ns
> I1105 14:34:10.041256  6554 master.hpp:419] Adding offer 201311051434-16777343-48584-6532-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201311051434-16777343-48584-6532-0 (localhost.localdomain)
> I1105 14:34:10.041291  6554 master.cpp:1661] Sending 1 offers to framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.041365  6554 sched.cpp:493] Scheduler::resourceOffers took 17056ns
> I1105 14:34:10.043416  6553 slave.cpp:567] Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_ReconcileTasksMissingFromSlave_Dcb21i/meta/slaves/201311051434-16777343-48584-6532-0/slave.info'
> I1105 14:34:10.044950  6554 master.cpp:1987] Processing reply for offer 201311051434-16777343-48584-6532-0 on slave 201311051434-16777343-48584-6532-0 (localhost.localdomain) for framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.045035  6554 master.hpp:391] Adding task ad5cdd09-9cc6-46db-9c15-529de151bdef with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201311051434-16777343-48584-6532-0 (localhost.localdomain)
> I1105 14:34:10.045078  6554 master.cpp:2111] Launching task ad5cdd09-9cc6-46db-9c15-529de151bdef of framework 201311051434-16777343-48584-6532-0000 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201311051434-16777343-48584-6532-0 (localhost.localdomain)
> I1105 14:34:10.045164  6554 master.hpp:429] Removing offer 201311051434-16777343-48584-6532-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201311051434-16777343-48584-6532-0 (localhost.localdomain)
> I1105 14:34:10.045233  6554 slave.cpp:728] Got assigned task ad5cdd09-9cc6-46db-9c15-529de151bdef for framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.045296  6554 slave.cpp:2872] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_ReconcileTasksMissingFromSlave_Dcb21i/meta/slaves/201311051434-16777343-48584-6532-0/frameworks/201311051434-16777343-48584-6532-0000/framework.info'
> I1105 14:34:10.045644  6554 slave.cpp:2879] Checkpointing framework pid 'scheduler(26)@127.0.0.1:48584' to '/tmp/SlaveRecoveryTest_0_ReconcileTasksMissingFromSlave_Dcb21i/meta/slaves/201311051434-16777343-48584-6532-0/frameworks/201311051434-16777343-48584-6532-0000/framework.pid'
> I1105 14:34:10.045933  6554 slave.cpp:839] Launching task ad5cdd09-9cc6-46db-9c15-529de151bdef for framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.048192  6554 slave.cpp:3136] Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_ReconcileTasksMissingFromSlave_Dcb21i/meta/slaves/201311051434-16777343-48584-6532-0/frameworks/201311051434-16777343-48584-6532-0000/executors/ad5cdd09-9cc6-46db-9c15-529de151bdef/executor.info'
> I1105 14:34:10.049345  6553 process_isolator.cpp:100] Launching ad5cdd09-9cc6-46db-9c15-529de151bdef (/var/jenkins/workspace/mesos-centos-6-gcc/src/mesos-executor) in /tmp/SlaveRecoveryTest_0_ReconcileTasksMissingFromSlave_Dcb21i/slaves/201311051434-16777343-48584-6532-0/frameworks/201311051434-16777343-48584-6532-0000/executors/ad5cdd09-9cc6-46db-9c15-529de151bdef/runs/32ce6c23-945b-4e98-a5da-a95dc9c60d01 with resources ' for framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.051753  6554 slave.cpp:3225] Checkpointing TaskInfo to '/tmp/SlaveRecoveryTest_0_ReconcileTasksMissingFromSlave_Dcb21i/meta/slaves/201311051434-16777343-48584-6532-0/frameworks/201311051434-16777343-48584-6532-0000/executors/ad5cdd09-9cc6-46db-9c15-529de151bdef/runs/32ce6c23-945b-4e98-a5da-a95dc9c60d01/tasks/ad5cdd09-9cc6-46db-9c15-529de151bdef/task.info'
> I1105 14:34:10.052595  6554 slave.cpp:949] Queuing task 'ad5cdd09-9cc6-46db-9c15-529de151bdef' for executor ad5cdd09-9cc6-46db-9c15-529de151bdef of framework '201311051434-16777343-48584-6532-0000
> I1105 14:34:10.053016  6554 slave.cpp:470] Successfully attached file '/tmp/SlaveRecoveryTest_0_ReconcileTasksMissingFromSlave_Dcb21i/slaves/201311051434-16777343-48584-6532-0/frameworks/201311051434-16777343-48584-6532-0000/executors/ad5cdd09-9cc6-46db-9c15-529de151bdef/runs/32ce6c23-945b-4e98-a5da-a95dc9c60d01'
> I1105 14:34:10.053657  6553 process_isolator.cpp:163] Forked executor at 7360
> I1105 14:34:10.054141  6553 slave.cpp:2074] Monitoring executor ad5cdd09-9cc6-46db-9c15-529de151bdef of framework 201311051434-16777343-48584-6532-0000 forked at pid 7360
> Checkpointing executor's forked pid 7360 to '/tmp/SlaveRecoveryTest_0_ReconcileTasksMissingFromSlave_Dcb21i/meta/slaves/201311051434-16777343-48584-6532-0/frameworks/201311051434-16777343-48584-6532-0000/executors/ad5cdd09-9cc6-46db-9c15-529de151bdef/runs/32ce6c23-945b-4e98-a5da-a95dc9c60d01/pids/forked.pid'
> Fetching resources into '/tmp/SlaveRecoveryTest_0_ReconcileTasksMissingFromSlave_Dcb21i/slaves/201311051434-16777343-48584-6532-0/frameworks/201311051434-16777343-48584-6532-0000/executors/ad5cdd09-9cc6-46db-9c15-529de151bdef/runs/32ce6c23-945b-4e98-a5da-a95dc9c60d01'
> WARNING: Logging before InitGoogleLogging() is written to STDERR
> I1105 14:34:10.122092  7360 process.cpp:1555] libprocess is initialized on 127.0.0.1:35194 for 4 cpus
> I1105 14:34:10.125159  7394 exec.cpp:174] Executor started at: executor(1)@127.0.0.1:35194 with pid 7360
> I1105 14:34:10.126044  6553 slave.cpp:1411] Got registration for executor 'ad5cdd09-9cc6-46db-9c15-529de151bdef' of framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.126096  6553 slave.cpp:1496] Checkpointing executor pid 'executor(1)@127.0.0.1:35194' to '/tmp/SlaveRecoveryTest_0_ReconcileTasksMissingFromSlave_Dcb21i/meta/slaves/201311051434-16777343-48584-6532-0/frameworks/201311051434-16777343-48584-6532-0000/executors/ad5cdd09-9cc6-46db-9c15-529de151bdef/runs/32ce6c23-945b-4e98-a5da-a95dc9c60d01/pids/libprocess.pid'
> I1105 14:34:10.126628  6553 slave.cpp:1532] Flushing queued task ad5cdd09-9cc6-46db-9c15-529de151bdef for executor 'ad5cdd09-9cc6-46db-9c15-529de151bdef' of framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.127213  7395 process.cpp:986] Socket closed while receiving
> I1105 14:34:10.127620  7394 exec.cpp:198] Executor registered on slave 201311051434-16777343-48584-6532-0
> IRegistered executor on localhost.localdomain
> 1105 14:34:10.128975  7394 exec.cpp:210] Executor::registered took 112142ns
> I1105 14:34:10.129631  7394 exec.cpp:285] Executor asked to run task 'ad5cdd09-9cc6-46db-9c15-529de151bdef'
> IStarting task ad5cdd09-9cc6-46db-9c15-529de151bdef
> 1105 14:34:10.129887  7394 exec.cpp:294] Executor::launchTask took 62381ns
> Forked command at 7396
> I1105 14:34:10.132583  7391 exec.cpp:505] Executor sending status update TASK_RUNNING (UUID: 316663ca-01e4-4de9-b37e-a50c39346d64) for task ad5cdd09-9cc6-46db-9c15-529de151bdef of framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.133277  6553 slave.cpp:1745] Handling status update TASK_RUNNING (UUID: 316663ca-01e4-4de9-b37e-a50c39346d64) for task ad5cdd09-9cc6-46db-9c15-529de151bdef of framework 201311051434-16777343-48584-6532-0000 from executor(1)@127.0.0.1:35194
> I1105 14:34:10.133385  6553 status_update_manager.cpp:305] Received status update TASK_RUNNING (UUID: 316663ca-01e4-4de9-b37e-a50c39346d64) for task ad5cdd09-9cc6-46db-9c15-529de151bdef of framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.133399  6553 status_update_manager.cpp:476] Creating StatusUpdate stream for task ad5cdd09-9cc6-46db-9c15-529de151bdef of framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.133723  6553 status_update_manager.hpp:337] Checkpointing UPDATE for status update TASK_RUNNING (UUID: 316663ca-01e4-4de9-b37e-a50c39346d64) for task ad5cdd09-9cc6-46db-9c15-529de151bdef of framework 201311051434-16777343-48584-6532-0000
> sh -c 'sleep 10'
> I1105 14:34:10.144309  6553 status_update_manager.cpp:356] Forwarding status update TASK_RUNNING (UUID: 316663ca-01e4-4de9-b37e-a50c39346d64) for task ad5cdd09-9cc6-46db-9c15-529de151bdef of framework 201311051434-16777343-48584-6532-0000 to master@127.0.0.1:48584
> I1105 14:34:10.144551  6553 master.cpp:1418] Status update TASK_RUNNING (UUID: 316663ca-01e4-4de9-b37e-a50c39346d64) for task ad5cdd09-9cc6-46db-9c15-529de151bdef of framework 201311051434-16777343-48584-6532-0000 from slave(37)@127.0.0.1:48584
> I1105 14:34:10.144590  6553 slave.cpp:1864] Status update manager successfully handled status update TASK_RUNNING (UUID: 316663ca-01e4-4de9-b37e-a50c39346d64) for task ad5cdd09-9cc6-46db-9c15-529de151bdef of framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.144600  6553 slave.cpp:1870] Sending acknowledgement for status update TASK_RUNNING (UUID: 316663ca-01e4-4de9-b37e-a50c39346d64) for task ad5cdd09-9cc6-46db-9c15-529de151bdef of framework 201311051434-16777343-48584-6532-0000 to executor(1)@127.0.0.1:35194
> I1105 14:34:10.144863  6553 sched.cpp:548] Scheduler::statusUpdate took 18056ns
> I1105 14:34:10.144965  6553 status_update_manager.cpp:380] Received status update acknowledgement (UUID: 316663ca-01e4-4de9-b37e-a50c39346d64) for task ad5cdd09-9cc6-46db-9c15-529de151bdef of framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.144985  6553 status_update_manager.hpp:337] Checkpointing ACK for status update TASK_RUNNING (UUID: 316663ca-01e4-4de9-b37e-a50c39346d64) for task ad5cdd09-9cc6-46db-9c15-529de151bdef of framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.145359  7395 process.cpp:986] Socket closed while receiving
> I1105 14:34:10.145499  7392 exec.cpp:331] Executor received status update acknowledgement 316663ca-01e4-4de9-b37e-a50c39346d64 for task ad5cdd09-9cc6-46db-9c15-529de151bdef of framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.155704  6554 slave.cpp:1351] Status update manager successfully handled status update acknowledgement (UUID: 316663ca-01e4-4de9-b37e-a50c39346d64) for task ad5cdd09-9cc6-46db-9c15-529de151bdef of framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.155897  6532 slave.cpp:395] Slave terminating
> I1105 14:34:10.157667  6552 master.cpp:624] Slave 201311051434-16777343-48584-6532-0 (localhost.localdomain) disconnected
> I1105 14:34:10.157986  6552 hierarchical_allocator_process.hpp:484] Slave 201311051434-16777343-48584-6532-0 disconnected
> I1105 14:34:10.161820  6553 slave.cpp:109] Slave started on 38)@127.0.0.1:48584
> I1105 14:34:10.161901  6553 slave.cpp:209] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I1105 14:34:10.162283  6553 slave.cpp:488] New master detected at master@127.0.0.1:48584
> I1105 14:34:10.162307  6553 slave.cpp:503] Postponing registration until recovery is complete
> I1105 14:34:10.162524  6553 status_update_manager.cpp:158] New master detected at master@127.0.0.1:48584
> I1105 14:34:10.162554  6553 state.cpp:33] Recovering state from '/tmp/SlaveRecoveryTest_0_ReconcileTasksMissingFromSlave_Dcb21i/meta'
> I1105 14:34:10.162870  6553 status_update_manager.cpp:180] Recovering status update manager
> I1105 14:34:10.162937  6553 process_isolator.cpp:314] Recovering isolator
> I1105 14:34:10.162999  6553 slave.cpp:2744] Finished recovery
> W1105 14:34:10.163125  6553 master.cpp:1276] Slave at slave(38)@127.0.0.1:48584 (localhost.localdomain) is being allowed to re-register with an already in use id (201311051434-16777343-48584-6532-0)
> W1105 14:34:10.163159  6553 master.cpp:2155] Sending TASK_LOST for task ad5cdd09-9cc6-46db-9c15-529de151bdef of framework 201311051434-16777343-48584-6532-0000 unknown to the slave 201311051434-16777343-48584-6532-0 (localhost.localdomain)
> I1105 14:34:10.163543  6552 slave.cpp:601] Re-registered with master master@127.0.0.1:48584
> I1105 14:34:10.164724  6555 sched.cpp:548] Scheduler::statusUpdate took 16651ns
> I1105 14:34:10.165279  6555 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 22584ns
> I1105 14:34:10.165441  6553 master.cpp:1418] Status update TASK_LOST (UUID: f2bc363b-8df6-48fd-9496-bbe23949cb12) for task ad5cdd09-9cc6-46db-9c15-529de151bdef of framework 201311051434-16777343-48584-6532-0000 from @0.0.0.0:0
> I1105 14:34:10.165793  6553 master.hpp:409] Removing task ad5cdd09-9cc6-46db-9c15-529de151bdef with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201311051434-16777343-48584-6532-0 (localhost.localdomain)
> I1105 14:34:10.166170  6552 hierarchical_allocator_process.hpp:637] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]) on slave 201311051434-16777343-48584-6532-0 from framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.166431  6555 hierarchical_allocator_process.hpp:498] Slave 201311051434-16777343-48584-6532-0 reconnected
> I1105 14:34:10.175914  6555 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201311051434-16777343-48584-6532-0 to framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.176023  6555 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 146305ns
> I1105 14:34:10.176087  6555 master.hpp:419] Adding offer 201311051434-16777343-48584-6532-1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201311051434-16777343-48584-6532-0 (localhost.localdomain)
> I1105 14:34:10.176127  6555 master.cpp:1661] Sending 1 offers to framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.176234  6555 sched.cpp:493] Scheduler::resourceOffers took 13276ns
> I1105 14:34:10.186714  6552 sched.cpp:651] Stopping framework '201311051434-16777343-48584-6532-0000'
> I1105 14:34:10.186918  6554 master.cpp:962] Asked to unregister framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.187033  6554 master.cpp:2346] Removing framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.187177  6554 master.hpp:429] Removing offer 201311051434-16777343-48584-6532-1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201311051434-16777343-48584-6532-0 (localhost.localdomain)
> GMOCK WARNING:
> Uninteresting mock function call - taking default action specified at:
> ./tests/mesos.hpp:332:
>     Function call: frameworkDeactivated(@0x7facb0001200 201311051434-16777343-48584-6532-0000)
> Stack trace:
> tests/slave_recovery_tests.cpp:1963: Failure
> Mock function called more times than expected - taking default action specified at:
> ./tests/mesos.hpp:356:
>     Function call: resourcesRecovered(@0x7facb0021f08 201311051434-16777343-48584-6532-0000, @0x7facb0021ee8 201311051434-16777343-48584-6532-0, @0x7facb0021eb0 { cpus(*):2, mem(*):1024, disk(*):1024, ports(*):[31000-32000] })
>          Expected: to be called once
> I1105 14:34:10.188154  6555 slave.cpp:1127] Asked to shut down framework 201311051434-16777343-48584-6532-0000 by master@127.0.0.1:48584
> W1105 14:34:10.188175  6555 slave.cpp:1142] Cannot shut down unknown framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.188220  6555 hierarchical_allocator_process.hpp:408] Deactivated framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.188287  6555 hierarchical_allocator_process.hpp:637] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]) on slave 201311051434-16777343-48584-6532-0 from framework 201311051434-16777343-48584-6532-0000
>            Actual: called twice - over-saturated and active
> GMOCK WARNING:
> Uninteresting mock function call - taking default action specified at:
> ./tests/mesos.hpp:326:
>     Function call: frameworkRemoved(@0x7facb0005a70 201311051434-16777343-48584-6532-0000)
> Stack trace:
> I1105 14:34:10.188863  6554 hierarchical_allocator_process.hpp:363] Removed framework 201311051434-16777343-48584-6532-0000
> I1105 14:34:10.189169  6532 master.cpp:566] Master terminating
> I1105 14:34:10.189193  6532 master.cpp:218] Shutting down master
> I1105 14:34:10.189199  6532 master.cpp:261] Removing slave 201311051434-16777343-48584-6532-0 (localhost.localdomain)
> I1105 14:34:10.189510  6532 slave.cpp:395] Slave terminating
> [  FAILED  ] SlaveRecoveryTest/0.ReconcileTasksMissingFromSlave, where TypeParam = mesos::internal::slave::ProcessIsolator (154 ms)



--
This message was sent by Atlassian JIRA
(v6.1#6144)