You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mesos.apache.org by Chengwei Yang <ch...@gmail.com> on 2015/02/03 14:46:24 UTC
When does scheduler driver send the LaunchTasksMessage
Hi List,
We are running chronos on mesos 0.19.0 and found a interesting problem, that if
we were trying to launch about 1k tasks in a single resourceOffers(), it may crash
and no tasks started by mesos at all.
So we did a test like below:
change code in chronos resourceOffers() callback as below:
1. print log
2. decline the first offer in bunch of offers
3. sleep 30 seconds
4. decline all the offers received
add a log in src/master/master.cpp to print some log whenever received a
LaunchTasksMessage, see below log.
-----------8<-----------------------
I0203 18:32:33.169342 7680 master.cpp:2939] Sending 3 offers to framework 20150203-174243-2487817994-5050-10996-0000
I0203 18:32:39.523227 7670 http.cpp:452] HTTP request for '/master/state.json'
I0203 18:32:49.601284 7674 http.cpp:452] HTTP request for '/master/state.json'
I0203 18:32:59.677875 7677 http.cpp:452] HTTP request for '/master/state.json'
I0203 18:33:03.390188 7676 master.cpp:1754] Received launchTasks message for offer [ 20150203-183014-2487817994-5050-7668-0 ] of framework 20150203-174243-2487817994-5050-10996-0000
I0203 18:33:03.390949 7676 master.cpp:1895] Processing reply for offers: [ 20150203-183014-2487817994-5050-7668-0 ] on slave 20150203-183014-2487817994-5050-7668-2 at slave(1)@10.23.73.140:5051 (xulijian-mesos-online016-cqdx.qiyi.virtual) for framework 20150203-174243-2487817994-5050-10996-0000
I0203 18:33:03.391469 7676 master.cpp:1754] Received launchTasks message for offer [ 20150203-183014-2487817994-5050-7668-0 ] of framework 20150203-174243-2487817994-5050-10996-0000
I0203 18:33:03.391791 7670 hierarchical_allocator_process.hpp:589] Framework 20150203-174243-2487817994-5050-10996-0000 filtered slave 20150203-183014-2487817994-5050-7668-2 for 5secs
W0203 18:33:03.392019 7676 master.cpp:1871] Failed to validate offer 20150203-183014-2487817994-5050-7668-0: Offer 20150203-183014-2487817994-5050-7668-0 is no longer valid
I0203 18:33:03.393173 7676 master.cpp:1754] Received launchTasks message for offer [ 20150203-183014-2487817994-5050-7668-1 ] of framework 20150203-174243-2487817994-5050-10996-0000
I0203 18:33:03.393601 7676 master.cpp:1895] Processing reply for offers: [ 20150203-183014-2487817994-5050-7668-1 ] on slave 20150203-183014-2487817994-5050-7668-1 at slave(1)@10.23.73.141:5051 (xulijian-mesos-online017-cqdx.qiyi.virtual) for framework 20150203-174243-2487817994-5050-10996-0000
I0203 18:33:03.394057 7676 master.cpp:1754] Received launchTasks message for offer [ 20150203-183014-2487817994-5050-7668-2 ] of framework 20150203-174243-2487817994-5050-10996-0000
I0203 18:33:03.394379 7679 hierarchical_allocator_process.hpp:589] Framework 20150203-174243-2487817994-5050-10996-0000 filtered slave 20150203-183014-2487817994-5050-7668-1 for 5secs
I0203 18:33:03.394664 7676 master.cpp:1895] Processing reply for offers: [ 20150203-183014-2487817994-5050-7668-2 ] on slave 20150203-183014-2487817994-5050-7668-0 at slave(1)@10.23.73.148:5051 (xulijian-mesos-online015-cqdx.qiyi.virtual) for framework 20150203-174243-2487817994-5050-10996-0000
I0203 18:33:03.395504 7676 hierarchical_allocator_process.hpp:589] Framework 20150203-174243-2487817994-5050-10996-0000 filtered slave 20150203-183014-2487817994-5050-7668-0 for 5secs
---------------8<-------------------
As we can see, mesos-master send offer to chronos at 18:32:33, but received all
4 decline message (LaunchTasksMessage) at 18:33.03, we are very curious why the
first decline doesn't sent before sleep 30 seconds?
From the log, we see that the offer 0 is no longer valid because we already send
a decline before.
Does that mean we(the framework scheduler) have to reply for all offers received
before we can launch any task?
--
Thanks,
Chengwei
Re: When does scheduler driver send the LaunchTasksMessage
Posted by Chengwei Yang <ch...@gmail.com>.
On Tue, Feb 03, 2015 at 05:52:48PM -0800, Adam Bordelon wrote:
> Also note that any unused resources from an offer passed to LaunchTasks will be
> automatically declined (and potentially reoffered with a new offerId).
> Thus, you cannot do "LaunchTasks(task1, offer1); LaunchTasks(task2, offer1);"
> since the remainder of offer1 will have been declined and any future
> LaunchTasks calls with it will be rejected.
Yes, thanks, we didn't do that, we launch multiple tasks for an offer with a
single launchTasks() call.
--
Thanks,
Chengwei
>
> On Tue, Feb 3, 2015 at 5:21 PM, Vinod Kone <vi...@apache.org> wrote:
>
> On Tue, Feb 3, 2015 at 5:46 AM, Chengwei Yang <ch...@gmail.com>
> wrote:
>
> > As we can see, mesos-master send offer to chronos at 18:32:33, but
> > received all
> > 4 decline message (LaunchTasksMessage) at 18:33.03, we are very curious
> > why the
> > first decline doesn't sent before sleep 30 seconds?
> >
>
> Just to be sure, if you sleep inside the callback any driver calls you make
> (launch/decline) will not be sent to the master until you return from the
> callback.
>
>
Re: When does scheduler driver send the LaunchTasksMessage
Posted by Adam Bordelon <ad...@mesosphere.io>.
Also note that any unused resources from an offer passed to LaunchTasks
will be automatically declined (and potentially reoffered with a new
offerId).
Thus, you cannot do "LaunchTasks(task1, offer1); LaunchTasks(task2,
offer1);" since the remainder of offer1 will have been declined and any
future LaunchTasks calls with it will be rejected.
On Tue, Feb 3, 2015 at 5:21 PM, Vinod Kone <vi...@apache.org> wrote:
> On Tue, Feb 3, 2015 at 5:46 AM, Chengwei Yang <ch...@gmail.com>
> wrote:
>
> > As we can see, mesos-master send offer to chronos at 18:32:33, but
> > received all
> > 4 decline message (LaunchTasksMessage) at 18:33.03, we are very curious
> > why the
> > first decline doesn't sent before sleep 30 seconds?
> >
>
> Just to be sure, if you sleep inside the callback any driver calls you make
> (launch/decline) will not be sent to the master until you return from the
> callback.
>
Re: When does scheduler driver send the LaunchTasksMessage
Posted by Chengwei Yang <ch...@gmail.com>.
I'm still a little confused as the document
http://mesos.apache.org/api/latest/java/org/apache/mesos/MesosSchedulerDriver.html
says:
> Note that blocking on the MesosSchedulerDriver (e.g., via join()) doesn't affect
> the scheduler callbacks in anyway because they are handled by a different
> thread.
My understand as below, *please* correct me if anything wrong.
the driver handle messages between scheduler and mesos, and start another thread
to handle callback(e.g. resourceOffers()) and wait(maybe join()) for the
callback thread.
Though the callback may signal the driver that have message to send(e.g.
launchTasks()), the driver is still waiting for callback thread finished, and
will continue to handle event(from mesos, to mesos) once the callback thread
exit.
--
Thanks,
Chengwei
On Wed, Feb 04, 2015 at 10:53:51AM -0800, Vinod Kone wrote:
> You are understanding is right. The driver is single threaded. So, if it is
> busy in a callback it can't send a message to the master.
>
> On Tue, Feb 3, 2015 at 7:04 PM, Chengwei Yang <ch...@gmail.com>
> wrote:
>
> On Tue, Feb 03, 2015 at 05:21:55PM -0800, Vinod Kone wrote:
> >
> > On Tue, Feb 3, 2015 at 5:46 AM, Chengwei Yang <chengwei.yang.cn@gmail.com
> >
> > wrote:
> >
> > As we can see, mesos-master send offer to chronos at 18:32:33, but
> received
> > all
> > 4 decline message (LaunchTasksMessage) at 18:33.03, we are very
> curious why
> > the
> > first decline doesn't sent before sleep 30 seconds?
> >
> >
> > Just to be sure, if you sleep inside the callback any driver calls you
> make
> > (launch/decline) will not be sent to the master until you return from the
> > callback.
> >
>
> Thanks Vinod, so if I understand correctly you did mean that all calls to
> driver->launchTasks() will to be send at the time it returns from
> resourceOffers() callback?
>
> For example, a pesudo code snippet like blow:
>
> resourceOffers() {
> foreach offer:offers; do
> // construct task
> driver->launchTasks(offer, tasks);
> }
>
> though there isn't any sleep in resourceOffers, but all the tasks only be
> sent
> to mesos-master at the time resourceOffers() finished? rather than sent
> when
> resourceOffers is running as the above code says?
>
> --
> Thanks,
> Chengwei
>
>
Re: When does scheduler driver send the LaunchTasksMessage
Posted by Vinod Kone <vi...@apache.org>.
You are understanding is right. The driver is single threaded. So, if it is
busy in a callback it can't send a message to the master.
On Tue, Feb 3, 2015 at 7:04 PM, Chengwei Yang <ch...@gmail.com>
wrote:
> On Tue, Feb 03, 2015 at 05:21:55PM -0800, Vinod Kone wrote:
> >
> > On Tue, Feb 3, 2015 at 5:46 AM, Chengwei Yang <
> chengwei.yang.cn@gmail.com>
> > wrote:
> >
> > As we can see, mesos-master send offer to chronos at 18:32:33, but
> received
> > all
> > 4 decline message (LaunchTasksMessage) at 18:33.03, we are very
> curious why
> > the
> > first decline doesn't sent before sleep 30 seconds?
> >
> >
> > Just to be sure, if you sleep inside the callback any driver calls you
> make
> > (launch/decline) will not be sent to the master until you return from the
> > callback.
> >
>
> Thanks Vinod, so if I understand correctly you did mean that all calls to
> driver->launchTasks() will to be send at the time it returns from
> resourceOffers() callback?
>
> For example, a pesudo code snippet like blow:
>
> resourceOffers() {
> foreach offer:offers; do
> // construct task
> driver->launchTasks(offer, tasks);
> }
>
> though there isn't any sleep in resourceOffers, but all the tasks only be
> sent
> to mesos-master at the time resourceOffers() finished? rather than sent
> when
> resourceOffers is running as the above code says?
>
> --
> Thanks,
> Chengwei
>
Re: When does scheduler driver send the LaunchTasksMessage
Posted by Chengwei Yang <ch...@gmail.com>.
On Tue, Feb 03, 2015 at 05:21:55PM -0800, Vinod Kone wrote:
>
> On Tue, Feb 3, 2015 at 5:46 AM, Chengwei Yang <ch...@gmail.com>
> wrote:
>
> As we can see, mesos-master send offer to chronos at 18:32:33, but received
> all
> 4 decline message (LaunchTasksMessage) at 18:33.03, we are very curious why
> the
> first decline doesn't sent before sleep 30 seconds?
>
>
> Just to be sure, if you sleep inside the callback any driver calls you make
> (launch/decline) will not be sent to the master until you return from the
> callback.
>
Thanks Vinod, so if I understand correctly you did mean that all calls to
driver->launchTasks() will to be send at the time it returns from
resourceOffers() callback?
For example, a pesudo code snippet like blow:
resourceOffers() {
foreach offer:offers; do
// construct task
driver->launchTasks(offer, tasks);
}
though there isn't any sleep in resourceOffers, but all the tasks only be sent
to mesos-master at the time resourceOffers() finished? rather than sent when
resourceOffers is running as the above code says?
--
Thanks,
Chengwei
Re: When does scheduler driver send the LaunchTasksMessage
Posted by Vinod Kone <vi...@apache.org>.
On Tue, Feb 3, 2015 at 5:46 AM, Chengwei Yang <ch...@gmail.com>
wrote:
> As we can see, mesos-master send offer to chronos at 18:32:33, but
> received all
> 4 decline message (LaunchTasksMessage) at 18:33.03, we are very curious
> why the
> first decline doesn't sent before sleep 30 seconds?
>
Just to be sure, if you sleep inside the callback any driver calls you make
(launch/decline) will not be sent to the master until you return from the
callback.
Re: When does scheduler driver send the LaunchTasksMessage
Posted by Chengwei Yang <ch...@gmail.com>.
On Tue, Feb 03, 2015 at 07:28:37AM -0800, Adam Bordelon wrote:
> Just make sure you only send one LaunchTasksMessage per slave, although that
> message could contain multiple tasks launched on a collection of offers from
> the same slave.
Yes, generally we use the *deprecated* launchTasks with a single offer.
> You mention that launching 1000s in the same message causes Mesos to crash. Do
> you have a crash stack available for this?
See here.
https://issues.apache.org/jira/browse/MESOS-1804
https://issues.apache.org/jira/browse/MESOS-1795
> You shouldn't have to respond to all offers received before tasks get launched.
Thanks!
> Some frameworks "hoard" offers in case they want to launch something on them
> later, but launch other tasks in the meantime. Perhaps the delay has something
> to do with Chronos' cron-like scheduling feature?
I'll confirm this and keep you update.
--
Thanks,
Chengwei
>
> On Tue, Feb 3, 2015 at 5:46 AM, Chengwei Yang <ch...@gmail.com>
> wrote:
>
> Hi List,
>
> We are running chronos on mesos 0.19.0 and found a interesting problem,
> that if
> we were trying to launch about 1k tasks in a single resourceOffers(), it
> may crash
> and no tasks started by mesos at all.
>
> So we did a test like below:
>
> change code in chronos resourceOffers() callback as below:
>
> 1. print log
> 2. decline the first offer in bunch of offers
> 3. sleep 30 seconds
> 4. decline all the offers received
>
> add a log in src/master/master.cpp to print some log whenever received a
> LaunchTasksMessage, see below log.
>
> -----------8<-----------------------
> I0203 18:32:33.169342 7680 master.cpp:2939] Sending 3 offers to framework
> 20150203-174243-2487817994-5050-10996-0000
> I0203 18:32:39.523227 7670 http.cpp:452] HTTP request for '/master/
> state.json'
> I0203 18:32:49.601284 7674 http.cpp:452] HTTP request for '/master/
> state.json'
> I0203 18:32:59.677875 7677 http.cpp:452] HTTP request for '/master/
> state.json'
> I0203 18:33:03.390188 7676 master.cpp:1754] Received launchTasks message
> for offer [ 20150203-183014-2487817994-5050-7668-0 ] of framework
> 20150203-174243-2487817994-5050-10996-0000
> I0203 18:33:03.390949 7676 master.cpp:1895] Processing reply for offers: [
> 20150203-183014-2487817994-5050-7668-0 ] on slave
> 20150203-183014-2487817994-5050-7668-2 at slave(1)@10.23.73.140:5051
> (xulijian-mesos-online016-cqdx.qiyi.virtual) for framework
> 20150203-174243-2487817994-5050-10996-0000
> I0203 18:33:03.391469 7676 master.cpp:1754] Received launchTasks message
> for offer [ 20150203-183014-2487817994-5050-7668-0 ] of framework
> 20150203-174243-2487817994-5050-10996-0000
> I0203 18:33:03.391791 7670 hierarchical_allocator_process.hpp:589]
> Framework 20150203-174243-2487817994-5050-10996-0000 filtered slave
> 20150203-183014-2487817994-5050-7668-2 for 5secs
> W0203 18:33:03.392019 7676 master.cpp:1871] Failed to validate offer
> 20150203-183014-2487817994-5050-7668-0: Offer
> 20150203-183014-2487817994-5050-7668-0 is no longer valid
> I0203 18:33:03.393173 7676 master.cpp:1754] Received launchTasks message
> for offer [ 20150203-183014-2487817994-5050-7668-1 ] of framework
> 20150203-174243-2487817994-5050-10996-0000
> I0203 18:33:03.393601 7676 master.cpp:1895] Processing reply for offers: [
> 20150203-183014-2487817994-5050-7668-1 ] on slave
> 20150203-183014-2487817994-5050-7668-1 at slave(1)@10.23.73.141:5051
> (xulijian-mesos-online017-cqdx.qiyi.virtual) for framework
> 20150203-174243-2487817994-5050-10996-0000
> I0203 18:33:03.394057 7676 master.cpp:1754] Received launchTasks message
> for offer [ 20150203-183014-2487817994-5050-7668-2 ] of framework
> 20150203-174243-2487817994-5050-10996-0000
> I0203 18:33:03.394379 7679 hierarchical_allocator_process.hpp:589]
> Framework 20150203-174243-2487817994-5050-10996-0000 filtered slave
> 20150203-183014-2487817994-5050-7668-1 for 5secs
> I0203 18:33:03.394664 7676 master.cpp:1895] Processing reply for offers: [
> 20150203-183014-2487817994-5050-7668-2 ] on slave
> 20150203-183014-2487817994-5050-7668-0 at slave(1)@10.23.73.148:5051
> (xulijian-mesos-online015-cqdx.qiyi.virtual) for framework
> 20150203-174243-2487817994-5050-10996-0000
> I0203 18:33:03.395504 7676 hierarchical_allocator_process.hpp:589]
> Framework 20150203-174243-2487817994-5050-10996-0000 filtered slave
> 20150203-183014-2487817994-5050-7668-0 for 5secs
> ---------------8<-------------------
>
> As we can see, mesos-master send offer to chronos at 18:32:33, but received
> all
> 4 decline message (LaunchTasksMessage) at 18:33.03, we are very curious why
> the
> first decline doesn't sent before sleep 30 seconds?
>
> >From the log, we see that the offer 0 is no longer valid because we
> already send
> a decline before.
>
> Does that mean we(the framework scheduler) have to reply for all offers
> received
> before we can launch any task?
>
> --
> Thanks,
> Chengwei
>
>
Re: When does scheduler driver send the LaunchTasksMessage
Posted by Adam Bordelon <ad...@mesosphere.io>.
Just make sure you only send one LaunchTasksMessage per slave, although
that message could contain multiple tasks launched on a collection of
offers from the same slave.
You mention that launching 1000s in the same message causes Mesos to crash.
Do you have a crash stack available for this?
You shouldn't have to respond to all offers received before tasks get
launched. Some frameworks "hoard" offers in case they want to launch
something on them later, but launch other tasks in the meantime. Perhaps
the delay has something to do with Chronos' cron-like scheduling feature?
On Tue, Feb 3, 2015 at 5:46 AM, Chengwei Yang <ch...@gmail.com>
wrote:
> Hi List,
>
> We are running chronos on mesos 0.19.0 and found a interesting problem,
> that if
> we were trying to launch about 1k tasks in a single resourceOffers(), it
> may crash
> and no tasks started by mesos at all.
>
> So we did a test like below:
>
> change code in chronos resourceOffers() callback as below:
>
> 1. print log
> 2. decline the first offer in bunch of offers
> 3. sleep 30 seconds
> 4. decline all the offers received
>
> add a log in src/master/master.cpp to print some log whenever received a
> LaunchTasksMessage, see below log.
>
> -----------8<-----------------------
> I0203 18:32:33.169342 7680 master.cpp:2939] Sending 3 offers to framework
> 20150203-174243-2487817994-5050-10996-0000
> I0203 18:32:39.523227 7670 http.cpp:452] HTTP request for
> '/master/state.json'
> I0203 18:32:49.601284 7674 http.cpp:452] HTTP request for
> '/master/state.json'
> I0203 18:32:59.677875 7677 http.cpp:452] HTTP request for
> '/master/state.json'
> I0203 18:33:03.390188 7676 master.cpp:1754] Received launchTasks message
> for offer [ 20150203-183014-2487817994-5050-7668-0 ] of framework
> 20150203-174243-2487817994-5050-10996-0000
> I0203 18:33:03.390949 7676 master.cpp:1895] Processing reply for offers:
> [ 20150203-183014-2487817994-5050-7668-0 ] on slave
> 20150203-183014-2487817994-5050-7668-2 at slave(1)@10.23.73.140:5051
> (xulijian-mesos-online016-cqdx.qiyi.virtual) for framework
> 20150203-174243-2487817994-5050-10996-0000
> I0203 18:33:03.391469 7676 master.cpp:1754] Received launchTasks message
> for offer [ 20150203-183014-2487817994-5050-7668-0 ] of framework
> 20150203-174243-2487817994-5050-10996-0000
> I0203 18:33:03.391791 7670 hierarchical_allocator_process.hpp:589]
> Framework 20150203-174243-2487817994-5050-10996-0000 filtered slave
> 20150203-183014-2487817994-5050-7668-2 for 5secs
> W0203 18:33:03.392019 7676 master.cpp:1871] Failed to validate offer
> 20150203-183014-2487817994-5050-7668-0: Offer
> 20150203-183014-2487817994-5050-7668-0 is no longer valid
> I0203 18:33:03.393173 7676 master.cpp:1754] Received launchTasks message
> for offer [ 20150203-183014-2487817994-5050-7668-1 ] of framework
> 20150203-174243-2487817994-5050-10996-0000
> I0203 18:33:03.393601 7676 master.cpp:1895] Processing reply for offers:
> [ 20150203-183014-2487817994-5050-7668-1 ] on slave
> 20150203-183014-2487817994-5050-7668-1 at slave(1)@10.23.73.141:5051
> (xulijian-mesos-online017-cqdx.qiyi.virtual) for framework
> 20150203-174243-2487817994-5050-10996-0000
> I0203 18:33:03.394057 7676 master.cpp:1754] Received launchTasks message
> for offer [ 20150203-183014-2487817994-5050-7668-2 ] of framework
> 20150203-174243-2487817994-5050-10996-0000
> I0203 18:33:03.394379 7679 hierarchical_allocator_process.hpp:589]
> Framework 20150203-174243-2487817994-5050-10996-0000 filtered slave
> 20150203-183014-2487817994-5050-7668-1 for 5secs
> I0203 18:33:03.394664 7676 master.cpp:1895] Processing reply for offers:
> [ 20150203-183014-2487817994-5050-7668-2 ] on slave
> 20150203-183014-2487817994-5050-7668-0 at slave(1)@10.23.73.148:5051
> (xulijian-mesos-online015-cqdx.qiyi.virtual) for framework
> 20150203-174243-2487817994-5050-10996-0000
> I0203 18:33:03.395504 7676 hierarchical_allocator_process.hpp:589]
> Framework 20150203-174243-2487817994-5050-10996-0000 filtered slave
> 20150203-183014-2487817994-5050-7668-0 for 5secs
> ---------------8<-------------------
>
> As we can see, mesos-master send offer to chronos at 18:32:33, but
> received all
> 4 decline message (LaunchTasksMessage) at 18:33.03, we are very curious
> why the
> first decline doesn't sent before sleep 30 seconds?
>
> From the log, we see that the offer 0 is no longer valid because we
> already send
> a decline before.
>
> Does that mean we(the framework scheduler) have to reply for all offers
> received
> before we can launch any task?
>
> --
> Thanks,
> Chengwei
>