mesos-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Paul Bell <arach...@gmail.com>
Subject Re: Consequences of health-check timeouts?
Date Wed, 18 May 2016 11:11:02 GMT
Hi Hasodent,

Thanks for your reply.

In re executor_shutdown_grace_period: how would this enable the task
(MongoDB) to terminate gracefully? (BTW: I am fairly certain that the mongo
STDOUT as captured by Mesos shows that it received signal 15 just before it
said good-bye). My naive understanding of this grace period is that it
simply delays the termination of the executor.

The following snippet is rom /var/log/syslog. I believe it shows the stack
trace (largely in the kernel) that led to mesos-master being blocked for
more than 120 seconds. Please note that immediately above (before) the
blocked mesos-master is a blocked jbd2/dm. Immediately below (after) the
blocked mesos-master is a blocked java task. I'm not sure what the java
task is. This took place on the mesos-master node and none of our
applications runs there. It runs master, Marathon, and ZK. Maybe the java
task is Marathon or ZK?

Thanks again.

-Paul

May 16 20:06:53 71 kernel: [193339.890848] INFO: task mesos-master:4013
blocked for more than 120 seconds.

May 16 20:06:53 71 kernel: [193339.890873]       Not tainted
3.13.0-32-generic #57-Ubuntu

May 16 20:06:53 71 kernel: [193339.890889] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.

May 16 20:06:53 71 kernel: [193339.890912] mesos-master    D
ffff88013fd94440     0  4013      1 0x00000000

May 16 20:06:53 71 kernel: [193339.890914]  ffff880137429a28
0000000000000002 ffff880135778000 ffff880137429fd8

May 16 20:06:53 71 kernel: [193339.890916]  0000000000014440
0000000000014440 ffff880135778000 ffff88013fd94cd8

May 16 20:06:53 71 kernel: [193339.890918]  ffff88013ffd34b0
0000000000000002 ffffffff81284630 ffff880137429aa0

May 16 20:06:53 71 kernel: [193339.890919] Call Trace:

May 16 20:06:53 71 kernel: [193339.890922]  [<ffffffff81284630>] ?
start_this_handle+0x590/0x590

May 16 20:06:53 71 kernel: [193339.890924]  [<ffffffff817203fd>]
io_schedule+0x9d/0x140

May 16 20:06:53 71 kernel: [193339.890925]  [<ffffffff8128463e>]
sleep_on_shadow_bh+0xe/0x20

May 16 20:06:53 71 kernel: [193339.890927]  [<ffffffff81720882>]
__wait_on_bit+0x62/0x90

May 16 20:06:53 71 kernel: [193339.890929]  [<ffffffff81284630>] ?
start_this_handle+0x590/0x590

May 16 20:06:53 71 kernel: [193339.890930]  [<ffffffff81720927>]
out_of_line_wait_on_bit+0x77/0x90

May 16 20:06:53 71 kernel: [193339.890932]  [<ffffffff810aaf40>] ?
autoremove_wake_function+0x40/0x40

May 16 20:06:53 71 kernel: [193339.890934]  [<ffffffff810aab15>] ?
wake_up_bit+0x25/0x30

May 16 20:06:53 71 kernel: [193339.890936]  [<ffffffff81285a3d>]
do_get_write_access+0x2ad/0x4f0

May 16 20:06:53 71 kernel: [193339.890938]  [<ffffffff811ef90d>] ?
__getblk+0x2d/0x2e0

May 16 20:06:53 71 kernel: [193339.890939]  [<ffffffff81285ca7>]
jbd2_journal_get_write_access+0x27/0x40

May 16 20:06:53 71 kernel: [193339.890942]  [<ffffffff8126c37b>]
__ext4_journal_get_write_access+0x3b/0x80

May 16 20:06:53 71 kernel: [193339.890946]  [<ffffffff81242200>]
ext4_reserve_inode_write+0x70/0xa0

May 16 20:06:53 71 kernel: [193339.890948]  [<ffffffff81245490>] ?
ext4_dirty_inode+0x40/0x60

May 16 20:06:53 71 kernel: [193339.890949]  [<ffffffff81242274>]
ext4_mark_inode_dirty+0x44/0x1f0

May 16 20:06:53 71 kernel: [193339.890951]  [<ffffffff81245490>]
ext4_dirty_inode+0x40/0x60

May 16 20:06:53 71 kernel: [193339.890953]  [<ffffffff811e65aa>]
__mark_inode_dirty+0x10a/0x2d0

May 16 20:06:53 71 kernel: [193339.890956]  [<ffffffff811d7761>]
update_time+0x81/0xd0

May 16 20:06:53 71 kernel: [193339.890957]  [<ffffffff811d7970>]
file_update_time+0x80/0xd0

May 16 20:06:53 71 kernel: [193339.890961]  [<ffffffff8114fc40>]
__generic_file_aio_write+0x180/0x3d0

May 16 20:06:53 71 kernel: [193339.890963]  [<ffffffff8114fee8>]
generic_file_aio_write+0x58/0xa0

May 16 20:06:53 71 kernel: [193339.890965]  [<ffffffff81239ea9>]
ext4_file_write+0x99/0x400

May 16 20:06:53 71 kernel: [193339.890967]  [<ffffffff8109a7f0>] ?
wake_up_state+0x10/0x20

May 16 20:06:53 71 kernel: [193339.890970]  [<ffffffff810d7c56>] ?
wake_futex+0x66/0x90

May 16 20:06:53 71 kernel: [193339.890972]  [<ffffffff810d8c01>] ?
futex_wake+0x1b1/0x1d0

May 16 20:06:53 71 kernel: [193339.890974]  [<ffffffff811bc3da>]
do_sync_write+0x5a/0x90

May 16 20:06:53 71 kernel: [193339.890976]  [<ffffffff811bcb64>]
vfs_write+0xb4/0x1f0

May 16 20:06:53 71 kernel: [193339.890978]  [<ffffffff811bd599>]
SyS_write+0x49/0xa0

May 16 20:06:53 71 kernel: [193339.890980]  [<ffffffff8172c87f>]
tracesys+0xe1/0xe6



On Wed, May 18, 2016 at 2:33 AM, haosdent <haosdent@gmail.com> wrote:

> >Is there some way to be given control (a callback, or an "exit" routine)
> so that the container about to be nuked can be given a chance to exit
> gracefully?
> The default value of executor_shutdown_grace_period is 5 seconds, you
> could change it by specify the `--executor_shutdown_grace_period` flag when
> launch mesos agent.
>
> >Are there other steps I can take to avoid this mildly calamitous
> occurrence?
> >mesos-slaves get shutdown
> Do you know where your mesos-master stuck when it happens? Any error log
> or related log about this? In addition, is there any log when mesos-slave
> shut down?
>
> On Wed, May 18, 2016 at 6:12 AM, Paul Bell <arachweb@gmail.com> wrote:
>
>> Hi All,
>>
>> I probably have the following account partly wrong, but let me present it
>> just the same and those who know better can correct me as needed.
>>
>> I've an application that runs several MongoDB shards, each a Dockerized
>> container, each on a distinct node (VM); in fact, some of the VMs are on
>> separate ESXi hosts.
>>
>> I've lately seen situations where, because of very slow disks for the
>> database, the following sequence occurs (I think):
>>
>>    1. Linux (Ubuntu 14.04 LTS) virtual memory manager hits thresholds
>>    defined by vm.dirty_background_ratio and/or vm.dirty_ratio (probably both)
>>    2. Synchronous flushing of many, many pages occurs, writing to a slow
>>    disk
>>    3. (Around this time one might see in /var/log/syslog "task X blocked
>>    for more than 120 seconds" for all kinds of tasks, including mesos-master)
>>    4. mesos-slaves get shutdown (this is the part I'm unclear about; but
>>    I am quite certain that on 2 nodes the executors and their in-flight
>>    MongoDB tasks got zapped because I can see that Marathon restarted them).
>>
>> The consequences of this are a corrupt MongoDB database. In the case at
>> hand, the job had run for over 50 hours, processing close to 120 million
>> files.
>>
>> Steps I've taken so far to remedy include:
>>
>>    - tune vm.dirty_background_ratio and vm.dirty_ratio down,
>>    respectively, to 5 and 10 (from 10 and 20). The intent here is to tolerate
>>    more frequent, smaller flushes and thus avoid less frequent massive flushes
>>    that suspend threads for very long periods.
>>    - increase agent ping timeout to 10 minutes (every 30 seconds, 20
>>    times)
>>
>> So the questions are:
>>
>>    - Is there some way to be given control (a callback, or an "exit"
>>    routine) so that the container about to be nuked can be given a chance to
>>    exit gracefully?
>>    - Are there other steps I can take to avoid this mildly calamitous
>>    occurrence?
>>    - (Also, I'd be grateful for more clarity on anything in steps 1-4
>>    above that is a bit hand-wavy!)
>>
>> As always, thanks.
>>
>> -Paul
>>
>>
>>
>
>
> --
> Best Regards,
> Haosdent Huang
>

Mime
View raw message