Yes, Shutdown callback is invoked in a thread, and mesos driver does stop() right after that which causes executor exit without completing the shutdown. I will raise issue for it in mesos-go github.
Really appreciate your help! Thanks, Jiamin > On Jul 24, 2017, at 11:03 AM, Vinod Kone <vinodk...@apache.org> wrote: > > I missed the fact that mesos-go is an executor driver implementation and it > doesn't have any bearing with the project maintained C++ executor driver > library. > > Looking at the go driver code, looks like the driver does a `stop()` when > it gets a shutdown message from the agent. This will likely cause the > driver and the executor to exit immediately. This is different > <https://github.com/apache/mesos/blob/master/src/exec/exec.cpp#L428 > <https://github.com/apache/mesos/blob/master/src/exec/exec.cpp#L428>> from > how the C++ driver responds to the shutdown message. > > Also, since you are using a 3rd party library, I would recommend asking > questions about it on the project's mailing list or opening up Issues in > GitHub. > > Thanks, > Vinod > > > On Fri, Jul 21, 2017 at 4:37 PM, Zhu Jiamin <jiamin.zhu...@gmail.com > <mailto:jiamin.zhu...@gmail.com>> wrote: > >> I enabled glog of mesos driver. Log below for scenario — sequence as >> follows: >> >> 1) shutdown slave >> 2) monitor agent status in mesos until it shows as “LOST” >> 3) start slave back up >> 4) Logs below from executor driver code: https://github.com/mesos/ >> <https://github.com/mesos/> >> mesos-go/blob/master/api/v0/executor/executor.go#L484-L501 < >> https://github.com/mesos/mesos-go/blob/master/api/v0/ >> <https://github.com/mesos/mesos-go/blob/master/api/v0/> >> executor/executor.go#L484-L501> >> >> I0721 22:20:20.007127 27249 executor.go:377] Executor driver reconnect >> I0721 22:20:20.007156 27249 executor.go:387] Received reconnect request >> from slave &SlaveID{Value:*7716ab68-bf95-4fd6-9d07-aa3fd4a65349-S9,XXX_ >> unrecognized:[],} >> I0721 22:20:20.008659 27249 executor.go:340] Executor driver reregistered >> I0721 22:20:20.008674 27249 executor.go:351] Re-registered on slave >> &SlaveID{Value:*7716ab68-bf95-4fd6-9d07-aa3fd4a65349-S9,XXX_ >> unrecognized:[],} >> I0721 22:20:20.008704 27249 main.go:52] Re-registered Executor on slave >> I0721 22:20:22.988835 27249 executor.go:509] Executor driver received >> shutdown >> I0721 22:20:22.988854 27249 executor.go:516] Executor driver is asked to >> shutdown >> I0721 22:20:22.988878 27249 executor.go:602] Stopping the executor driver >> I0721 22:20:22.988885 27249 messenger.go:295] stopping messenger >> executor(1)@127.0.0.1:52644.. >> I0721 22:20:22.988896 27249 http_transporter.go:447] stopping HTTP >> transport >> >> >> >> I also put a sleep in Shutdown callback: https://github.com/mesos/ >> mesos-go/blob/master/api/v0/examples/executor/main.go#L110 < >> https://github.com/mesos/mesos-go/blob/master/api/v0/ >> <https://github.com/mesos/mesos-go/blob/master/api/v0/> >> examples/executor/main.go#L110> >> >> However, I expected Shutdown callback getting invoked but don’t see in >> logs.. it seems likely that executor got terminated abruptly. May be abort >> or stop is invoked prior to shutdown?. >> >> Would you verify behavior from your end for this scenario.. >> >> >> >> Thanks, >> Jiamin >> >> >> >> >> >> >> >> >>> On Jul 18, 2017, at 5:42 PM, Zhu Jiamin <jiamin.zhu...@gmail.com> wrote: >>> >>> mesos-go executor driver calls driver.stop() after invoking shutdown of >> executor >>> >>> // this is from mesos-go executor driver >>> driver.withExecutor(func(e Executor) { e.Shutdown(driver) }) >>> driver.stop() >>> >>> So executor should print log firstly then exit since driver stop happen >> after invoking shutdown. >>> >>> Will try to enable GLOG and come back to you. >>> >>> Many thanks, >>> Jiamin >>> >>> >>> >>> >>> >>>> On Jul 18, 2017, at 5:24 PM, Vinod Kone <vinodk...@apache.org >>>> <mailto:vinodk...@apache.org> <mailto: >> vinodk...@apache.org <mailto:vinodk...@apache.org>>> wrote: >>>> >>>> On Tue, Jul 18, 2017 at 2:11 PM, Zhu Jiamin <jiamin.zhu...@gmail.com >>>> <mailto:jiamin.zhu...@gmail.com> >> <mailto:jiamin.zhu...@gmail.com <mailto:jiamin.zhu...@gmail.com>>> wrote: >>>> >>>>> 2017/07/18 20:49:19 Stop driver >>>>> >>>> >>>> Am I reading this correctly that mesos-go executor calls `stop()` on the >>>> driver? Do you know if it calls it when it gets a `shutdown()`? If yes, >>>> that would explain the behavior. >>>> >>>> Looking at the driver code, looks like when it gets a shutdown message >> from >>>> the agent the shutdown grace period should be respected. The only way a >>>> driver would terminate early is if an executor called `stop()` or >> `abort()` >>>> in the interim. >>>> >>>> Is there any way you could set `GLOG_v=1` in the environment of your >>>> executor so that driver logs get output? That would make debugging this >>>> much easier.
