Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.debian.user > #205228 > unrolled thread

Bug with soft raid?

Back to article view | Back to linux.debian.user

Contents

  Bug with soft raid? steve <dlist@bluewin.ch> - 2019-02-12 12:10 +0100
    Re: Bug with soft raid? David Christensen <dpchrist@holgerdanske.com> - 2019-02-12 16:20 +0100
    Re: Bug with soft raid? Tom Bachreier <mr.tom-mldu-20181127@tuta.io> - 2019-02-12 20:40 +0100
      Re: Bug with soft raid? David Christensen <dpchrist@holgerdanske.com> - 2019-02-12 21:50 +0100
        Re: Bug with soft raid? David Christensen <dpchrist@holgerdanske.com> - 2019-02-13 19:30 +0100
          Re: Bug with soft raid? Claudio Kuenzler <ck@claudiokuenzler.com> - 2019-02-13 20:00 +0100
      Re: Bug with soft raid? steve <dlist@bluewin.ch> - 2019-02-15 09:40 +0100
        Re: Bug with soft raid? Andy Smith <andy@strugglers.net> - 2019-02-15 15:20 +0100
          Re: Bug with soft raid? steve <dlist@bluewin.ch> - 2019-02-20 09:20 +0100
    Re: Bug with soft raid? "Alexander V. Makartsev" <avbetev@gmail.com> - 2019-02-12 22:30 +0100

#205228 — Bug with soft raid?

Hi There,

Here is what I get on my up to date stretch box:

Feb 10 12:19:12 box kernel: [ 7734.562060] INFO: task md0_raid1:461 blocked for more than 120 seconds.
Feb 10 12:19:12 box kernel: [ 7734.562068]       Tainted: P           OE     4.19.0-0.bpo.1-amd64 #1 Debian 4.19.12-1~bpo9+1
Feb 10 12:19:12 box kernel: [ 7734.562070] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 10 12:19:12 box kernel: [ 7734.562074] md0_raid1       D    0   461      2 0x80000000
Feb 10 12:19:12 box kernel: [ 7734.562078] Call Trace:
Feb 10 12:19:12 box kernel: [ 7734.562093]  ? __schedule+0x3f5/0x880
Feb 10 12:19:12 box kernel: [ 7734.562098]  schedule+0x32/0x80
Feb 10 12:19:12 box kernel: [ 7734.562112]  md_super_wait+0x6e/0xa0 [md_mod]
Feb 10 12:19:12 box kernel: [ 7734.562120]  ? remove_wait_queue+0x60/0x60
Feb 10 12:19:12 box kernel: [ 7734.562128]  md_update_sb.part.61+0x4af/0x910 [md_mod]
Feb 10 12:19:12 box kernel: [ 7734.562136]  md_check_recovery+0x312/0x530 [md_mod]
Feb 10 12:19:12 box kernel: [ 7734.562143]  raid1d+0x60/0x8c0 [raid1]
Feb 10 12:19:12 box kernel: [ 7734.562149]  ? schedule+0x32/0x80
Feb 10 12:19:12 box kernel: [ 7734.562152]  ? schedule_timeout+0x1e5/0x350
Feb 10 12:19:12 box kernel: [ 7734.562159]  ? md_thread+0x125/0x170 [md_mod]
Feb 10 12:19:12 box kernel: [ 7734.562165]  md_thread+0x125/0x170 [md_mod]
Feb 10 12:19:12 box kernel: [ 7734.562170]  ? remove_wait_queue+0x60/0x60
Feb 10 12:19:12 box kernel: [ 7734.562174]  kthread+0xf8/0x130
Feb 10 12:19:12 box kernel: [ 7734.562180]  ? md_rdev_init+0xc0/0xc0 [md_mod]
Feb 10 12:19:12 box kernel: [ 7734.562183]  ? kthread_create_worker_on_cpu+0x70/0x70
Feb 10 12:19:12 box kernel: [ 7734.562186]  ret_from_fork+0x35/0x40
Feb 10 12:19:12 box kernel: [ 7734.562192] INFO: task md1_raid1:468 blocked for more than 120 seconds.
Feb 10 12:19:12 box kernel: [ 7734.562196]       Tainted: P           OE     4.19.0-0.bpo.1-amd64 #1 Debian 4.19.12-1~bpo9+1
Feb 10 12:19:12 box kernel: [ 7734.562198] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 10 12:19:12 box kernel: [ 7734.562200] md1_raid1       D    0   468      2 0x80000000
Feb 10 12:19:12 box kernel: [ 7734.562203] Call Trace:
Feb 10 12:19:12 box kernel: [ 7734.562209]  ? __schedule+0x3f5/0x880
Feb 10 12:19:12 box kernel: [ 7734.562213]  schedule+0x32/0x80
Feb 10 12:19:12 box kernel: [ 7734.562219]  md_super_wait+0x6e/0xa0 [md_mod]
Feb 10 12:19:12 box kernel: [ 7734.562224]  ? remove_wait_queue+0x60/0x60
Feb 10 12:19:12 box kernel: [ 7734.562230]  md_update_sb.part.61+0x4af/0x910 [md_mod]
Feb 10 12:19:12 box kernel: [ 7734.562237]  md_check_recovery+0x312/0x530 [md_mod]
Feb 10 12:19:12 box kernel: [ 7734.562241]  raid1d+0x60/0x8c0 [raid1]
Feb 10 12:19:12 box kernel: [ 7734.562246]  ? schedule+0x32/0x80
Feb 10 12:19:12 box kernel: [ 7734.562248]  ? schedule_timeout+0x1e5/0x350
Feb 10 12:19:12 box kernel: [ 7734.562255]  ? md_thread+0x125/0x170 [md_mod]
Feb 10 12:19:12 box kernel: [ 7734.562260]  md_thread+0x125/0x170 [md_mod]
Feb 10 12:19:12 box kernel: [ 7734.562265]  ? remove_wait_queue+0x60/0x60
Feb 10 12:19:12 box kernel: [ 7734.562268]  kthread+0xf8/0x130
Feb 10 12:19:12 box kernel: [ 7734.562274]  ? md_rdev_init+0xc0/0xc0 [md_mod]
Feb 10 12:19:12 box kernel: [ 7734.562276]  ? kthread_create_worker_on_cpu+0x70/0x70
Feb 10 12:19:12 box kernel: [ 7734.562279]  ret_from_fork+0x35/0x40
Feb 10 12:19:12 box kernel: [ 7734.562366] INFO: task fetchmail:3277 blocked for more than 120 seconds.
Feb 10 12:19:12 box kernel: [ 7734.562369]       Tainted: P           OE     4.19.0-0.bpo.1-amd64 #1 Debian 4.19.12-1~bpo9+1
Feb 10 12:19:12 box kernel: [ 7734.562371] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 10 12:19:12 box kernel: [ 7734.562373] fetchmail       D    0  3277      1 0x00000080
Feb 10 12:19:12 box kernel: [ 7734.562376] Call Trace:
Feb 10 12:19:12 box kernel: [ 7734.562381]  ? __schedule+0x3f5/0x880
Feb 10 12:19:12 box kernel: [ 7734.562412]  ? __ext4_handle_dirty_metadata+0x51/0x1a0 [ext4]
Feb 10 12:19:12 box kernel: [ 7734.562418]  schedule+0x32/0x80
Feb 10 12:19:12 box kernel: [ 7734.562426]  md_write_start+0x13c/0x210 [md_mod]
Feb 10 12:19:12 box kernel: [ 7734.562432]  ? remove_wait_queue+0x60/0x60
Feb 10 12:19:12 box kernel: [ 7734.562437]  raid1_make_request+0x63/0xbc0 [raid1]
Feb 10 12:19:12 box kernel: [ 7734.562442]  ? mempool_alloc+0x69/0x190
Feb 10 12:19:12 box kernel: [ 7734.562446]  ? bvec_alloc+0x86/0xe0
Feb 10 12:19:12 box kernel: [ 7734.562453]  md_handle_request+0x116/0x190 [md_mod]
Feb 10 12:19:12 box kernel: [ 7734.562460]  md_make_request+0x72/0x170 [md_mod]
Feb 10 12:19:12 box kernel: [ 7734.562465]  generic_make_request+0x1e7/0x410
Feb 10 12:19:12 box kernel: [ 7734.562471]  ? submit_bio+0x6c/0x140
Feb 10 12:19:12 box kernel: [ 7734.562474]  submit_bio+0x6c/0x140
Feb 10 12:19:12 box kernel: [ 7734.562500]  ext4_io_submit+0x49/0x60 [ext4]
Feb 10 12:19:12 box kernel: [ 7734.562519]  ext4_writepages+0x621/0xe00 [ext4]
Feb 10 12:19:12 box kernel: [ 7734.562526]  ? do_writepages+0x1a/0x60
Feb 10 12:19:12 box kernel: [ 7734.562529]  do_writepages+0x1a/0x60
Feb 10 12:19:12 box kernel: [ 7734.562533]  __filemap_fdatawrite_range+0xc8/0x100
Feb 10 12:19:12 box kernel: [ 7734.562552]  ext4_rename+0x676/0x900 [ext4]


and so one.

The system blocks for about 3 minutes and then I get back a hand on it.

I'm no specialist so I don't know what to do. 

Any help would appreciated.

Best,
Steve

[toc] | [next] | [standalone]

#205239

On 2/12/19 3:08 AM, steve wrote:
> Hi There,
> 
> Here is what I get on my up to date stretch box:
> 
> Feb 10 12:19:12 box kernel: [ 7734.562060] INFO: task md0_raid1:461 
> blocked for more than 120 seconds.

<snip>

> and so one.
> 
> The system blocks for about 3 minutes and then I get back a hand on it.
> 
> I'm no specialist so I don't know what to do.
> Any help would appreciated.
> 
> Best,
> Steve

Backup your data.


Download the manufacturer's diagnostic toolkit for your disks and run 
it.  Note that some tools require a Windows or MacOS installation.  I 
prefer bootable tools, when available.  For example:

   Seatools Bootable:

     https://www.seagate.com/support/downloads/seatools/


Reply with the results.


David

[toc] | [prev] | [next] | [standalone]

#205247

Feb 12, 2019, 12:08 PM by dlist@bluewin.ch:

> Hi There,
>
> Here is what I get on my up to date stretch box:
>
> Feb 10 12:19:12 box kernel: [ 7734.562060] INFO: task md0_raid1:461 blocked for more than 120 seconds.
> [...]
> Feb 10 12:19:12 box kernel: [ 7734.562192] INFO: task md1_raid1:468 blocked for more than 120 seconds.
> [...]
> Feb 10 12:19:12 box kernel: [ 7734.562366] INFO: task fetchmail:3277 blocked for more than 120 seconds.
>
>
> and so one.
>
> The system blocks for about 3 minutes and then I get back a hand on it.
>
>

Hi Steve!

I have a similar - maybe the same - problem in buster - see the thread
"Software RAID blocks" on this list about a month ago. Unfortunately
still no solution. :-(

I have the advantage that my system harddisk is outside the RAID on a
separate disk. Therefore I'm still able to send "low level" commands
like smartctl or fdisk to the disks in the array during the block. If
I trigger the right disk the block aborts immediately.

Maybe this works for you, too?
You can try:

for i in /dev/sd{b..f}; do echo "DISK: ${i}"; smartctl -l scterc "${i}"; sleep 3; done

or:

for i in /dev/sd{b..f}; do echo "DISK: ${i}"; fdisk -l "${i}"; sleep 3; done

My RAID disks are sdb, sdc, sdd, sde, sdf. You have to change sd{b..f}
above according to your setup.

I use a 3 second delay between the disk to be able to tell which disk
was responsible for the block.

Hope this helps a little.

Tom

[toc] | [prev] | [next] | [standalone]

#205250

On 2/12/19 11:37 AM, Tom Bachreier wrote:
> 
> 
> Feb 12, 2019, 12:08 PM by dlist@bluewin.ch:
>> The system blocks for about 3 minutes and then I get back a hand on it.
> 
> I have a similar - maybe the same - problem in buster - see the thread
> "Software RAID blocks" on this list about a month ago. Unfortunately
> still no solution. :-(
> 
> I have the advantage that my system harddisk is outside the RAID on a
> separate disk. Therefore I'm still able to send "low level" commands
> like smartctl or fdisk to the disks in the array during the block. If
> I trigger the right disk the block aborts immediately.

In each of my machines, I use a single 16 GB USB 3.0 flash drive, or a 
small SDD, for the system drive.  I then use btrfs for all file systems. 
  It is my expectation that if a disk goes bad, the machine will log an 
error and/or halt.


> Maybe this works for you, too?
> You can try:
> 
> for i in /dev/sd{b..f}; do echo "DISK: ${i}"; smartctl -l scterc "${i}"; sleep 3; done

Some drives allow you to adjust the Error Recovery Control timeout in 
their firmware.  You can use this to force the drive to return an error 
promptly, rather than spending minutes trying to recover (e.g. block for 
3 minutes):

https://en.wikipedia.org/wiki/Error_recovery_control


I had a Linux md RAID0 (mirror) built from two older desktop/ SOHO 
server drives that supported scterc.  So, I put commands like the 
following, one per drive, into a script that was run at system startup:

     # /usr/sbin/smartctl -l scterc,70,70 /dev/disk/by-id/ata-XXX_YYY
     smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.9.0-4-amd64] (local 
build)
     Copyright (C) 2002-16, Bruce Allen, Christian Franke, 
www.smartmontools.org

     SCT Error Recovery Control set to:
                Read:     70 (7.0 seconds)
               Write:     70 (7.0 seconds)


David

[toc] | [prev] | [next] | [standalone]

#205305

On 2/12/19 12:48 PM, David Christensen wrote:
> I had a Linux md RAID0 (mirror) ...

Correction -- RAID1 is mirror.


David

[toc] | [prev] | [next] | [standalone]

#205307

[Multipart message — attachments visible in raw view] — view raw

Hello Steve,

As some of the other responders already said, check your drives' SMART
values.
But a disk may fail without any indication in the SMART table. I've seen
this a couple of years ago and documented it here:
https://www.claudiokuenzler.com/blog/301/disk-failure-not-detected-by-smart-ata1-failed-command
The errors you've seen are also kind of similar as the ones I saw (although
there are a couple of years in between, so Kernel messages might be a bit
different now).

Long story short: It was indeed a defect hard drive causing the problems
(and log entries).

On Wed, Feb 13, 2019 at 7:20 PM David Christensen <dpchrist@holgerdanske.com>
wrote:

> On 2/12/19 12:48 PM, David Christensen wrote:
> > I had a Linux md RAID0 (mirror) ...
>
> Correction -- RAID1 is mirror.
>
>
> David
>
>

[toc] | [prev] | [next] | [standalone]

#205361

Hi all,

Thank you for your answers. Was busy so couldn't answer before.

My system disk (with /, /usr, /boot and /boot/efi) is on a separate
(non-RAID) disk sda.


>Maybe this works for you, too?
>You can try:

cat /proc/mdstat 
Personalities : [linear] [multipath] [raid0] [raid1] [raid6] [raid5] [raid4] [raid10] 
md1 : active raid1 sdf5[3] sdc5[1] sdb5[2](S)
      117120896 blocks super 1.2 [2/2] [UU]
      
md2 : active raid1 sdf6[3] sdc6[1] sdb6[2](S)
      97589120 blocks super 1.2 [2/2] [UU]
      
md0 : active raid1 sdf1[3] sdc1[1] sdb1[2](S)
      19514240 blocks super 1.2 [2/2] [UU]


>for i in /dev/sd{b..f}; do echo "DISK: ${i}"; smartctl -l scterc "${i}"; sleep 3; done

I get this for sdb and sdc

SCT Error Recovery Control:
           Read: Disabled
          Write: Disabled


and this for sdf

SCT Error Recovery Control:
           Read:     70 (7.0 seconds)
          Write:     70 (7.0 seconds)


What does it tell me ?

[toc] | [prev] | [next] | [standalone]

#205378

Hi Steve,

On Fri, Feb 15, 2019 at 09:35:27AM +0100, steve wrote:
> >for i in /dev/sd{b..f}; do echo "DISK: ${i}"; smartctl -l scterc "${i}"; sleep 3; done
> 
> I get this for sdb and sdc
> 
> SCT Error Recovery Control:
>           Read: Disabled
>          Write: Disabled
> 
> and this for sdf
> 
> SCT Error Recovery Control:
>           Read:     70 (7.0 seconds)
>          Write:     70 (7.0 seconds)
> 
> What does it tell me ?

It means that sd[bc] may support SCTERC but it's disabled (promising),
and sdf does support it and it's set to 7 seconds (good).

For disks in Linux software RAID, SCTERC with a low timeout is
essential. If it's not possible then the block layer timeout for the
device should be increased.

You should try to set SCTERC for sd[bc] like so:

# for dev in /dev/sd[cd]; do smartctl -l scterc,70,70 "$dev"; done

If that works then great - all your drives support SCTERC and have low
timeouts.

If setting it to 70 (centiseconds, so 7 seconds) doesn't work then you
will need to increase the block layer timeout like this:

# for dev in sd[cd]; do echo 180 > /sys/block/sda/device/timeout; done

The reason to do this is that should any of your drives encounter a
problem reading or writing, without SCTERC set the drive will try very
hard to do whatever it was meant to be doing for a very long period of
time, and while it's doing that it will be unresponsive to anything
else.

The default block layer timeout is 30 seconds and a drive having
problems reading or writing just 1 sector can easily spend longer than
this trying to do so. Linux then drops the entire device from the array.
If you're lucky this only happens on the one device and you're able to
add it back in again, but a very common cause of arrays not assembling
or always having a device kicked out is these sorts of timeouts.

When using RAID it is much better to have the drive give up sooner as
the RAID should take care of what was unable to be read or written. So,
being able to set SCTERC is best, but failing that you really must set
the block layer timeout high enough.

The smartctl and /sys/block settings above don't survive a power cycle
so would need to be set at every boot.

Cheers,
Andy

-- 
https://bitfolk.com/ -- No-nonsense VPS hosting

[toc] | [prev] | [next] | [standalone]

#205537

Hello Andy,

Thank you very much for your lengthy and very informative answer.

After some investigation, I discovered that it was /dev/sdc that had
some problems. So I took it out of the Rais 1 array. But this didn't
really help since I got other freeze.

grep "120 seconds" kern.log
Feb 18 16:16:38 box kernel: [30209.474017] INFO: task md1_raid1:467 blocked for more than 120 seconds.
Feb 18 16:16:38 box kernel: [30209.474151] INFO: task md0_raid1:470 blocked for more than 120 seconds.
Feb 18 16:16:38 box kernel: [30209.474250] INFO: task jbd2/md0-8:982 blocked for more than 120 seconds.
Feb 18 16:16:38 box kernel: [30209.474447] INFO: task jbd2/md1-8:988 blocked for more than 120 seconds.
Feb 18 16:16:38 box kernel: [30209.474721] INFO: task configmgrWriter:26206 blocked for more than 120 seconds.
Feb 18 16:16:38 box kernel: [30209.474944] INFO: task kworker/u56:1:25006 blocked for more than 120 seconds.
Feb 18 16:16:38 box kernel: [30209.475150] INFO: task kworker/u56:2:26207 blocked for more than 120 seconds.
Feb 18 16:18:39 box kernel: [30330.307956] INFO: task md1_raid1:467 blocked for more than 120 seconds.
Feb 18 16:18:39 box kernel: [30330.308088] INFO: task md0_raid1:470 blocked for more than 120 seconds.
Feb 18 16:18:39 box kernel: [30330.308188] INFO: task jbd2/md0-8:982 blocked for more than 120 seconds.
Feb 19 11:03:22 box kernel: [ 8217.751926] INFO: task md0_raid1:412 blocked for more than 120 seconds.
Feb 19 11:03:22 box kernel: [ 8217.752059] INFO: task md1_raid1:416 blocked for more than 120 seconds.
Feb 19 11:03:22 box kernel: [ 8217.752158] INFO: task jbd2/md1-8:988 blocked for more than 120 seconds.
Feb 19 11:03:22 box kernel: [ 8217.752348] INFO: task jbd2/md0-8:993 blocked for more than 120 seconds.
Feb 19 11:03:22 box kernel: [ 8217.752513] INFO: task uptimed:1174 blocked for more than 120 seconds.
Feb 19 11:03:22 box kernel: [ 8217.752743] INFO: task fetchmail:3121 blocked for more than 120 seconds.
Feb 19 11:03:22 box kernel: [ 8217.752990] INFO: task offlineimap:4247 blocked for more than 120 seconds.
Feb 19 11:03:22 box kernel: [ 8217.753195] INFO: task kworker/u56:0:10116 blocked for more than 120 seconds.
Feb 19 11:03:22 box kernel: [ 8217.753390] INFO: task kworker/u56:2:11869 blocked for more than 120 seconds.
Feb 19 11:05:22 box kernel: [ 8338.585502] INFO: task md0_raid1:412 blocked for more than 120 seconds.

>On Fri, Feb 15, 2019 at 09:35:27AM +0100, steve wrote:
>> >for i in /dev/sd{b..f}; do echo "DISK: ${i}"; smartctl -l scterc "${i}"; sleep 3; done
>>
>> I get this for sdb and sdc
>>
>> SCT Error Recovery Control:
>>           Read: Disabled
>>          Write: Disabled
>>
>> and this for sdf
>>
>> SCT Error Recovery Control:
>>           Read:     70 (7.0 seconds)
>>          Write:     70 (7.0 seconds)
>>
>> What does it tell me ?
>
>It means that sd[bc] may support SCTERC but it's disabled (promising),
>and sdf does support it and it's set to 7 seconds (good).
>
>For disks in Linux software RAID, SCTERC with a low timeout is
>essential. If it's not possible then the block layer timeout for the
>device should be increased.
>
>You should try to set SCTERC for sd[bc] like so:
>
># for dev in /dev/sd[cd]; do smartctl -l scterc,70,70 "$dev"; done

I tried this:

smartctl -l scterc,70,70 /dev/sdb
smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.19.0-0.bpo.1-amd64] (local build)
Copyright (C) 2002-16, Bruce Allen, Christian Franke, www.smartmontools.org

SCT Error Recovery Control set to:
           Read:     70 (7.0 seconds)
          Write:     70 (7.0 seconds)

But then

smartctl -l scterc /dev/sdb
smartctl 6.6 2016-05-31 r4324 [x86_64-linux-4.19.0-0.bpo.1-amd64] (local build)
Copyright (C) 2002-16, Bruce Allen, Christian Franke, www.smartmontools.org

Unexpected SCT status 0x0046 (action_code=3, function_code=2)
SCT (Get) Error Recovery Control command failed


Which is weird…


>If that works then great - all your drives support SCTERC and have low
>timeouts.
>
>If setting it to 70 (centiseconds, so 7 seconds) doesn't work then you
>will need to increase the block layer timeout like this:

cat /sys/block/sdb/device/timeout 
30


echo 180 > /sys/block/sdb/device/timeout

Let's see if it helps.


I am here in a field that I don't master at all, so just following your advices.


Will let you know.

Thank you

Best,
Steve

[toc] | [prev] | [next] | [standalone]

#205251

[Multipart message — attachments visible in raw view] — view raw

On 12.02.2019 16:08, steve wrote:
> Hi There,
>
> Here is what I get on my up to date stretch box:
>
> Feb 10 12:19:12 box kernel: [ 7734.562060] INFO: task md0_raid1:461
> blocked for more than 120 seconds.
> Feb 10 12:19:12 box kernel: [ 7734.562068]       Tainted: P          
> OE     4.19.0-0.bpo.1-amd64 #1 Debian 4.19.12-1~bpo9+1
> Feb 10 12:19:12 box kernel: [ 7734.562070] "echo 0 >
> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> Feb 10 12:19:12 box kernel: [ 7734.562074] md0_raid1       D    0  
> 461      2 0x80000000
> Feb 10 12:19:12 box kernel: [ 7734.562078] Call Trace:
> Feb 10 12:19:12 box kernel: [ 7734.562093]  ? __schedule+0x3f5/0x880
> Feb 10 12:19:12 box kernel: [ 7734.562098]  schedule+0x32/0x80
> Feb 10 12:19:12 box kernel: [ 7734.562112]  md_super_wait+0x6e/0xa0
> [md_mod]
> Feb 10 12:19:12 box kernel: [ 7734.562120]  ? remove_wait_queue+0x60/0x60
> Feb 10 12:19:12 box kernel: [ 7734.562128] 
> md_update_sb.part.61+0x4af/0x910 [md_mod]
> Feb 10 12:19:12 box kernel: [ 7734.562136] 
> md_check_recovery+0x312/0x530 [md_mod]
> Feb 10 12:19:12 box kernel: [ 7734.562143]  raid1d+0x60/0x8c0 [raid1]
> Feb 10 12:19:12 box kernel: [ 7734.562149]  ? schedule+0x32/0x80
> Feb 10 12:19:12 box kernel: [ 7734.562152]  ?
> schedule_timeout+0x1e5/0x350
> Feb 10 12:19:12 box kernel: [ 7734.562159]  ? md_thread+0x125/0x170
> [md_mod]
> Feb 10 12:19:12 box kernel: [ 7734.562165]  md_thread+0x125/0x170
> [md_mod]
> Feb 10 12:19:12 box kernel: [ 7734.562170]  ? remove_wait_queue+0x60/0x60
> Feb 10 12:19:12 box kernel: [ 7734.562174]  kthread+0xf8/0x130
> Feb 10 12:19:12 box kernel: [ 7734.562180]  ? md_rdev_init+0xc0/0xc0
> [md_mod]
> Feb 10 12:19:12 box kernel: [ 7734.562183]  ?
> kthread_create_worker_on_cpu+0x70/0x70
> Feb 10 12:19:12 box kernel: [ 7734.562186]  ret_from_fork+0x35/0x40
> Feb 10 12:19:12 box kernel: [ 7734.562192] INFO: task md1_raid1:468
> blocked for more than 120 seconds.
> Feb 10 12:19:12 box kernel: [ 7734.562196]       Tainted: P          
> OE     4.19.0-0.bpo.1-amd64 #1 Debian 4.19.12-1~bpo9+1
> Feb 10 12:19:12 box kernel: [ 7734.562198] "echo 0 >
> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> Feb 10 12:19:12 box kernel: [ 7734.562200] md1_raid1       D    0  
> 468      2 0x80000000
> Feb 10 12:19:12 box kernel: [ 7734.562203] Call Trace:
> Feb 10 12:19:12 box kernel: [ 7734.562209]  ? __schedule+0x3f5/0x880
> Feb 10 12:19:12 box kernel: [ 7734.562213]  schedule+0x32/0x80
> Feb 10 12:19:12 box kernel: [ 7734.562219]  md_super_wait+0x6e/0xa0
> [md_mod]
> Feb 10 12:19:12 box kernel: [ 7734.562224]  ? remove_wait_queue+0x60/0x60
> Feb 10 12:19:12 box kernel: [ 7734.562230] 
> md_update_sb.part.61+0x4af/0x910 [md_mod]
> Feb 10 12:19:12 box kernel: [ 7734.562237] 
> md_check_recovery+0x312/0x530 [md_mod]
> Feb 10 12:19:12 box kernel: [ 7734.562241]  raid1d+0x60/0x8c0 [raid1]
> Feb 10 12:19:12 box kernel: [ 7734.562246]  ? schedule+0x32/0x80
> Feb 10 12:19:12 box kernel: [ 7734.562248]  ?
> schedule_timeout+0x1e5/0x350
> Feb 10 12:19:12 box kernel: [ 7734.562255]  ? md_thread+0x125/0x170
> [md_mod]
> Feb 10 12:19:12 box kernel: [ 7734.562260]  md_thread+0x125/0x170
> [md_mod]
> Feb 10 12:19:12 box kernel: [ 7734.562265]  ? remove_wait_queue+0x60/0x60
> Feb 10 12:19:12 box kernel: [ 7734.562268]  kthread+0xf8/0x130
> Feb 10 12:19:12 box kernel: [ 7734.562274]  ? md_rdev_init+0xc0/0xc0
> [md_mod]
> Feb 10 12:19:12 box kernel: [ 7734.562276]  ?
> kthread_create_worker_on_cpu+0x70/0x70
> Feb 10 12:19:12 box kernel: [ 7734.562279]  ret_from_fork+0x35/0x40
> Feb 10 12:19:12 box kernel: [ 7734.562366] INFO: task fetchmail:3277
> blocked for more than 120 seconds.
> Feb 10 12:19:12 box kernel: [ 7734.562369]       Tainted: P          
> OE     4.19.0-0.bpo.1-amd64 #1 Debian 4.19.12-1~bpo9+1
> Feb 10 12:19:12 box kernel: [ 7734.562371] "echo 0 >
> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> Feb 10 12:19:12 box kernel: [ 7734.562373] fetchmail       D    0 
> 3277      1 0x00000080
> Feb 10 12:19:12 box kernel: [ 7734.562376] Call Trace:
> Feb 10 12:19:12 box kernel: [ 7734.562381]  ? __schedule+0x3f5/0x880
> Feb 10 12:19:12 box kernel: [ 7734.562412]  ?
> __ext4_handle_dirty_metadata+0x51/0x1a0 [ext4]
> Feb 10 12:19:12 box kernel: [ 7734.562418]  schedule+0x32/0x80
> Feb 10 12:19:12 box kernel: [ 7734.562426]  md_write_start+0x13c/0x210
> [md_mod]
> Feb 10 12:19:12 box kernel: [ 7734.562432]  ? remove_wait_queue+0x60/0x60
> Feb 10 12:19:12 box kernel: [ 7734.562437] 
> raid1_make_request+0x63/0xbc0 [raid1]
> Feb 10 12:19:12 box kernel: [ 7734.562442]  ? mempool_alloc+0x69/0x190
> Feb 10 12:19:12 box kernel: [ 7734.562446]  ? bvec_alloc+0x86/0xe0
> Feb 10 12:19:12 box kernel: [ 7734.562453] 
> md_handle_request+0x116/0x190 [md_mod]
> Feb 10 12:19:12 box kernel: [ 7734.562460]  md_make_request+0x72/0x170
> [md_mod]
> Feb 10 12:19:12 box kernel: [ 7734.562465] 
> generic_make_request+0x1e7/0x410
> Feb 10 12:19:12 box kernel: [ 7734.562471]  ? submit_bio+0x6c/0x140
> Feb 10 12:19:12 box kernel: [ 7734.562474]  submit_bio+0x6c/0x140
> Feb 10 12:19:12 box kernel: [ 7734.562500]  ext4_io_submit+0x49/0x60
> [ext4]
> Feb 10 12:19:12 box kernel: [ 7734.562519] 
> ext4_writepages+0x621/0xe00 [ext4]
> Feb 10 12:19:12 box kernel: [ 7734.562526]  ? do_writepages+0x1a/0x60
> Feb 10 12:19:12 box kernel: [ 7734.562529]  do_writepages+0x1a/0x60
> Feb 10 12:19:12 box kernel: [ 7734.562533] 
> __filemap_fdatawrite_range+0xc8/0x100
> Feb 10 12:19:12 box kernel: [ 7734.562552]  ext4_rename+0x676/0x900
> [ext4]
>
>
> and so one.
>
> The system blocks for about 3 minutes and then I get back a hand on it.
>
> I'm no specialist so I don't know what to do.
> Any help would appreciated.
>
> Best,
> Steve
>
Seems like this behavior is explained in this article, including the
solution. [1] Not a bug, but something that requires an optimization
settings.
*But*, I'd first checked the disks for hardware problems and md array
for consistency, after complete data backup is made and verified, of
course, like David already suggested.

Depending on the drives they could be "slow" because of active APM
putting them to sleep state and causing them to spin down and park
heads, or they could be "slow" because of bad blocks are found and
drive's firmware trying to reallocate them. Bottom line is, you have to
ensure your hard drives are ok.
To investigate further, more information is required.
Get output of this command for each device:
    $ sudo smartctl --all /dev/sda
Also check current state of your md array:
    $ sudo mdadm --detail --scan --verbose
    $ cat /proc/mdstat

[1]
https://globalroot.wordpress.com/2015/02/13/linux-error-message-task-blocked-for-more-than-120-seconds/

-- 
With kindest regards, Alexander.

⢀⣴⠾⠻⢶⣦⠀ 
⣾⠁⢠⠒⠀⣿⡁ Debian - The universal operating system
⢿⡄⠘⠷⠚⠋⠀ https://www.debian.org
⠈⠳⣄⠀⠀⠀⠀ 

[toc] | [prev] | [standalone]

Back to top | Article view | linux.debian.user

csiph-web