mdadm causes boot to hang for 4 minutes

[Tom R]

32 bit Edgy beta.

bootchart: http://librarian.launchpad.net/4918059/edgy-20061021-1.png

One 160gb drive
 Partitions:
   * 1gig swap
   * 20gig root (ext3)
   * 20gig /home (ext3)
   * rest a data (no OS files) partition (vfat)

Two 250gb drives
   * one partion, in RAID1 array with mdadm (just used for data (no OS files), ext3)

I think I have an unconventional setup with my RAID array. I first created this array in Dapper. When I moved to Edgy, I did a fresh install from CD. After I had Edgy installed, I couldn't get my array to be assembled on boot, so after every boot, I would have to run this to get access to my data:

sudo mknod -m 0660 /dev/md0 b 9 0 && sudo mdadm --assemble /dev/md0 --scan && sudo mount /dev/md0 /raid-data/

mdadm.conf:
   DEVICE partitions
   ARRAY /dev/md0 level=raid1 num-devices=2 UUID=3dcc3d57:4499d301:a27ac102:cf8ea623

Every time I boot, grub loaded & booted to the splash. The progress bar would fill up maybe 5 millimeters then not go any further for about 5 seconds. After 5 seconds, it would go to a blank screen with a flashing underline in the top left corner.

It would stay at this point for roughly 4 minutes. Once this blank screen disappeared, the system continues to boot to the login screen. Pressing Ctrl+C or Ctrl+D has no effect.

If you look at the bootchart above, mdadm and a subprocess md seem to be running A LOT.

Because I am not a developer, I cannot give any technical information on this bug, apart from that a 5 minute boot time is very annoying.

[Dave Gilbert (ubuntu-treblig)]

Hi Tom,
  It looks like I'm falling over a similar problem to you in bug 68888; in my
case I think the problem is it doesn't like the format of my mdadm.conf; but
could you add to your report; the output of :

cat /proc/mdstat

and then for each of the partitions with the RAID on the output of

mdadm --examine /dev/xxxxx
(Where /dev/xxxxx replaced by your disc device).

[Tom R (asub)]

Hiya Dave,

Here's the info you asked for.

rixth@king:~$ cat /proc/mdstat
Personalities : [raid1]
md0 : active raid1 sdb[0] sdc[1]
      244198464 blocks [2/2] [UU]

unused devices: <none>
rixth@king:~$

rixth@king:~$ sudo mdadm --examine /dev/sdb
/dev/sdb:
          Magic : a92b4efc
        Version : 00.90.03
           UUID : 3dcc3d57:4499d301:a27ac102:cf8ea623
  Creation Time : Tue Aug 22 19:31:10 2006
     Raid Level : raid1
    Device Size : 244198464 (232.89 GiB 250.06 GB)
     Array Size : 244198464 (232.89 GiB 250.06 GB)
   Raid Devices : 2
  Total Devices : 2
Preferred Minor : 0

    Update Time : Sun Oct 29 14:52:28 2006
          State : clean
 Active Devices : 2
Working Devices : 2
 Failed Devices : 0
  Spare Devices : 0
       Checksum : 36917b01 - correct
         Events : 0.1893804

      Number Major Minor RaidDevice State
this 0 8 16 0 active sync /dev/sdb

   0 0 8 16 0 active sync /dev/sdb
   1 1 8 32 1 active sync /dev/sdc

rixth@king:~$ sudo mdadm --examine /dev/sdc
/dev/sdc:
          Magic : a92b4efc
        Version : 00.90.03
           UUID : 3dcc3d57:4499d301:a27ac102:cf8ea623
  Creation Time : Tue Aug 22 19:31:10 2006
     Raid Level : raid1
    Device Size : 244198464 (232.89 GiB 250.06 GB)
     Array Size : 244198464 (232.89 GiB 250.06 GB)
   Raid Devices : 2
  Total Devices : 2
Preferred Minor : 0

    Update Time : Sun Oct 29 14:52:34 2006
          State : clean
 Active Devices : 2
Working Devices : 2
 Failed Devices : 0
  Spare Devices : 0
       Checksum : 36917b1d - correct
         Events : 0.1893806

      Number Major Minor RaidDevice State
this 1 8 32 1 active sync /dev/sdc

   0 0 8 16 0 active sync /dev/sdb
   1 1 8 32 1 active sync /dev/sdc
rixth@king:~$

[Dave Gilbert (ubuntu-treblig)]

Hmm, maybe its not exactly the same problem as mine then - can you try:

cat /etc/mdadm/mdadm.conf | grep "UUID" | sed -e 's/.*=//g'

and add on here what it says - in principal it should be just the UUID

[Tom R (asub)]

It should be noted that I also have a card reader, as in bug #68888 but I unplugged it, and disabled USB boot in BIOS the problem remained.

Also, as you requested:

rixth@king:~$ cat /etc/mdadm/mdadm.conf | grep "UUID" | sed -e 's/.*=//g'
3dcc3d57:4499d301:a27ac102:cf8ea623
rixth@king:~$

Tom.

[Dave Gilbert (ubuntu-treblig)]

OK, it doesn't look quite the same problem I've got - for me that sed is producing rubbish and hence it never finds it (but I've not tried fixing that to see if the problem then goes away).
I'd suggest adding some debug to the beginning and end of that scripts and then rebuilding the initrd and see if you can see what it does.
(This is such a PITA to debug though, having to wait ~5-10mins for a reboot!).

Dave

[Istvan Botka (boti)]

There is a script /usr/share/initramfs-tools/scripts/local-top/md in the mdadm package.
It scans only the hda1, hda2, sda1, sdb2, etc but no the hda, hdb, sda, sdb.

There is a cycle in this script that wait 180 seconds on every boot for timeout of the scanning the possibly raid member disks to determine which raid level module need to load into the kernel.

[Tom R (asub)]

The wait for me is more than 3 minutes, though.

Any chance of a fix for this though?

[Istvan Botka (boti)]

Here is my patch for /usr/share/initramfs-tools/scripts/local-top/md

--- md.orig 2006-09-26 14:36:43.000000000 +0200
+++ md.fixed 2006-11-26 10:13:12.000000000 +0100
@@ -23,7 +23,7 @@

 # Detect raid level
 while [ "$configureduuids" ] && [ ${slumber} -gt 0 ]; do
- for x in /dev/hd[a-z][0-9]* /dev/sd[a-z][0-9]*; do
+ for x in /dev/hd[a-z] /dev/sd[a-z] /dev/hd[a-z][0-9]* /dev/sd[a-z][0-9]*; do
                if [ ! -e ${x} ]; then
                        continue
                fi

[Dave Gilbert (ubuntu-treblig)]

Be careful - while indeed this does seem a fix for this problem, this script needs a lot more work. Hard coding that fairly arbitrary list of devices is going to break again for someone with a more obscure device. (As a first example, when there are more than 26 scsi devices - and I've seen a system with many more than that, where you start going beyond sdz). Perhaps it needs to check /sys/devices/block or /proc/partition (and then not get hung up on floppies....)

The script also provides no feedback and no diags even when quiet is removed and you are just left with an apparent hang. It's parsing of mdadm.conf is also fairly basic (e.g. see #68888)

Dave

[Tom R (asub)]

Do I need to rebuild the initrd for this?

If so, how do I do it?

I did patch that script, but boot still took a long time so I assume there is another step.

[Tom R (asub)]

Ok, I found out how to rebuild the initrd, I can confirm this fixes the bug for me.

[Istvan Botka (boti)]

You're right. My fix works work in my and the two other reported case.
It is a quick and dirty fix for some special cases.
I have spent ~4-5 hours to catch this bug. (A reboot takes up to 10 minutes on my box when patch not included) It would have been take less time if the script would have some debug information.

[Oliver Payne (ompayne+launchpad)]

I have a RAID1 array built from two lvm2 regions (via EVMS). /proc/mdstat shows:

Personalities : [raid1]
md0 : active raid1 dm-11[1] dm-8[0]
      15335360 blocks [2/2] [UU]

unused devices: <none>

and /etc/mdadm/mdadm.conf contains:

DEVICE partitions
ARRAY /dev/md0 level=raid1 num-devices=2 UUID=3d92222f:a155e644:a2ab2e58:d2105214

It looks like /etc/init.d/evms loads all the necessary kernel modules (ie raid1 for me), which makes the md script redundant. However, it still hangs for a few minutes looking for RAID devices, even though their modules are already loaded.

[Istvan Botka (boti)]

Hi Oliver!

Could you send the output of mdadm -D /dev/md0 command also?

[Fabio Massimo Di Nitto (fabbione)]

too much handwaving.. eh..

[Fabio Massimo Di Nitto (fabbione)]

Ok to all submitters:

thanks a lot for the reports. Clearly i fucked this up and I am working on a proper fix. Stay tuned because i will need your help to test some cases like the one with sdv and so on.

Fabio

[Fabio Massimo Di Nitto (fabbione)]

I uploaded a new mdadm that should address all the issues (at least i really hope so) described in all bugs here:

http://people.ubuntu.com/~fabbione/67299/

I would be really glad if you could please test it in your environment (make sure your initramfs is updated) and let me know if it works. If so i will upload to edgy-proposed and later to edgy-updates.

Fabio

[Alan Tam (at)]

Any reason the loop max lasts for 180 seconds? I guess 15 or 30 seconds are pretty much enough (bug 73710).

[Sebastian Goth (seezer)]

Hi Fabio,

tried your patched mdadm and it works fine for me.
(I reported to bug 68888)

Edgy upgraded from dapper on i386 with kernel 2.6.17-10-generic.

mdadm.conf:
DEVICE /dev/hd[eg]1 /dev/md0
ARRAY /dev/md0 level=raid0 num-devices=2 auto=md UUID=de8de1a1:92bd24ff:71f87519:4adf71fd

Thank you for the work,
Sebastian

[Istvan Botka (boti)]

Hi Fabio!

I've tried the http://people.ubuntu.com/~fabbione/67299/ package on my amd64 box (it runs amd64).
It's working but complains on debug section (log_begin_msg and log_end_msg not found)
My RAID is an raid5 level array built from sd[a-d].

[Oliver Payne (ompayne+launchpad)]

Unfortunately, no joy here with the new version :-( Output from mdadm -D /dev/md0:

/dev/md0:
        Version : 00.90.03
  Creation Time : Thu Jun 29 22:56:50 2006
     Raid Level : raid1/dev/md0:
        Version : 00.90.03
  Creation Time : Thu Jun 29 22:56:50 2006
     Raid Level : raid1
     Array Size : 15335360 (14.62 GiB 15.70 GB)
    Device Size : 15335360 (14.62 GiB 15.70 GB)
   Raid Devices : 2
  Total Devices : 2
Preferred Minor : 0
    Persistence : Superblock is persistent

    Update Time : Wed Nov 29 21:38:00 2006
          State : clean
 Active Devices : 2
Working Devices : 2
 Failed Devices : 0
  Spare Devices : 0

           UUID : 3d92222f:a155e644:a2ab2e58:d2105214
         Events : 0.22849

    Number Major Minor RaidDevice State
       0 253 8 0 active sync /dev/evms/.nodes/lvm2/30G_container/backup1
       1 253 11 1 active sync /dev/evms/.nodes/lvm2/80G_container/backup2

     Array Size : 15335360 (14.62 GiB 15.70 GB)
    Device Size : 15335360 (14.62 GiB 15.70 GB)
   Raid Devices : 2
  Total Devices : 2
Preferred Minor : 0
    Persistence : Superblock is persistent

    Update Time : Wed Nov 29 21:38:00 2006
          State : clean
 Active Devices : 2
Working Devices : 2
 Failed Devices : 0
  Spare Devices : 0

           UUID : 3d92222f:a155e644:a2ab2e58:d2105214
         Events : 0.22849

    Number Major Minor RaidDevice State
       0 253 8 0 active sync /dev/evms/.nodes/lvm2/30G_container/backup1
       1 253 11 1 active sync /dev/evms/.nodes/lvm2/80G_container/backup2

Just to reiterate, the modules are (correctly) loaded by evms before md runs, so everything works fine, apart from the 3 minute delay on boot.

Thanks,

Oliver

[Fabio Massimo Di Nitto (fabbione)]

Alan Tam wrote:
> Any reason the loop max lasts for 180 seconds? I guess 15 or 30 seconds
> are pretty much enough (bug 73710).
>

Unfortunaly 15/30 seconds are not enough for all systems. In one of my test
cases I have devices appearing after a minute.

The problems that we are addressing here are different. First of all there is no
way to know when drivers will finish to scan a I/O subsystem and second we don't
know when udev will present all the devices to us.
From a pure theoretically point of view we should be waiting from boot to
shutdown.. yeah it's kind of weird idea and 3 minutes seems to fit 99.9999% of
the cases i could cover.

Fabio

--
I'm going to make him an offer he can't refuse.

[Fabio Massimo Di Nitto (fabbione)]

Istvan Botka wrote:
> Hi Fabio!
>
> I've tried the http://people.ubuntu.com/~fabbione/67299/ package on my amd64 box (it runs amd64).
> It's working but complains on debug section (log_begin_msg and log_end_msg not found)
> My RAID is an raid5 level array built from sd[a-d].
>

Oh i see.. i forgot to include the file with the functions. Minor detail ..
fixed in my local patches.

Fabio

--
I'm going to make him an offer he can't refuse.

[Fabio Massimo Di Nitto (fabbione)]

Oliver Payne wrote:
> Unfortunately, no joy here with the new version :-( Output from mdadm
> -D /dev/md0:

> Number Major Minor RaidDevice State
> 0 253 8 0 active sync /dev/evms/.nodes/lvm2/30G_container/backup1
> 1 253 11 1 active sync /dev/evms/.nodes/lvm2/80G_container/backup2

Are you running RAID over LVM?

> Just to reiterate, the modules are (correctly) loaded by evms before md
> runs, so everything works fine, apart from the 3 minute delay on boot.

and are you actually using evms for your disk management for real?

Fabio

--
I'm going to make him an offer he can't refuse.

[Oliver Payne (ompayne+launchpad)]

On 30/11/06, Fabio Massimo Di Nitto <email address hidden> wrote:
> Are you running RAID over LVM?

Yes.

> and are you actually using evms for your disk management for real?

Yes, I use evms for managing my filesystems. All my non-root
filesystems are lvm volumes. I also have a backup filesystem, which
is RAID1 built from two lvm volumes. This is what's causing the
problems.

Thanks for your efforts,

Oliver

[Fabio Massimo Di Nitto (fabbione)]

Oliver Payne wrote:
> On 30/11/06, Fabio Massimo Di Nitto <email address hidden> wrote:
>> Are you running RAID over LVM?
>
> Yes.

Ok.. this change totally the issue. lvm and evms are always executed after mdadm.

>
>> and are you actually using evms for your disk management for real?
>
> Yes, I use evms for managing my filesystems. All my non-root
> filesystems are lvm volumes. I also have a backup filesystem, which
> is RAID1 built from two lvm volumes. This is what's causing the
> problems.
>
> Thanks for your efforts,

I will upload mdadm now to solve the timeout issue for all the others but i will
need some more help from you to solve your problem in edgy. The issue will be
gone totally in feisty that will use a new design that will not require to rely
on any kind of initramfs scripts.

Fabio

--
I'm going to make him an offer he can't refuse.

[Oliver Payne (ompayne+launchpad)]

On 01/12/06, Fabio Massimo Di Nitto <email address hidden> wrote:
> I will upload mdadm now to solve the timeout issue for all the others but i will
> need some more help from you to solve your problem in edgy.

That sounds good. I'm happy to help however I can to sort this out.

Thanks,

Oliver

[Dave Gilbert (ubuntu-treblig)]

Hi Fabio,
  That deb seems to work fine for me (reporter of 68888); some comments:

1) The /etc/mdadm/mdadm.conf you create in the initrd is now very different from the mdadm.conf you would find in your running system - perhaps it should have a different name (mdadm.uuids ?)
   (Incidentally that is a wonderful sed line, I think I've managed to understand it all except for the '!' near the start of the first pattern)

2) I think it is actually just relying on finding at least one device out of each RAID - we seem to have a choice; ideally we would wait for all the elements of a RAID to get consistency, but if one of the devices has died what do we want to do? For a RAID5 we would want most of the devices to be there just to be able to get / up, and if the devices are on different controllers then there is no guarentee that one won't be a few seconds behind the other.

3) In the non-quiet case can you add a 'waiting for UUID's' and then list all the UUIDs in both the initial begin message and everytime we find one?

4) Why do you redirect errors from the modprobe to /dev/null? Wouldn't we want to know about the errors?

[Fabio Massimo Di Nitto (fabbione)]

Dave Gilbert wrote:
> Hi Fabio, That deb seems to work fine for me (reporter of 68888); some
> comments:
>
> 1) The /etc/mdadm/mdadm.conf you create in the initrd is now very different
> from the mdadm.conf you would find in your running system - perhaps it should
> have a different name (mdadm.uuids ?) (Incidentally that is a wonderful sed
> line, I think I've managed to understand it all except for the '!' near the
> start of the first pattern)

It's not necessary. You don't interact with that file directly and it's just a
cosmetic change. I need to keep the delta to fix these issues as small as
possible in order to make it into a stable release and this change is not really
required.

>
> 2) I think it is actually just relying on finding at least one device out of
> each RAID - we seem to have a choice; ideally we would wait for all the
> elements of a RAID to get consistency,

There is no easy way to do that. I have been there already and....

 but if one of the devices has died
> what do we want to do?

... there is no way to know if one of the devices is dead. We can't rely on the
md super block information since they might still report the device as active.

> For a RAID5 we would want most of the devices to be
> there just to be able to get / up, and if the devices are on different
> controllers then there is no guarentee that one won't be a few seconds behind
> the other.

As i said in one of the previous emails, there is no way to know when all
devices will be available to the point were the only moment that we will know
that is at shutdown (think at hot pluggable devices being part of a raid). So we
need to balance our choises and what to do.

> 3) In the non-quiet case can you add a 'waiting for UUID's' and then list all
> the UUIDs in both the initial begin message and everytime we find one?

No sorry.. as i said i need to keep the delta as small as possible. There are
already changes in the package that might be rejected by our QA team.

> 4) Why do you redirect errors from the modprobe to /dev/null? Wouldn't we
> want to know about the errors?

Because we know for a fact that if you are running an ubuntu kernel these
modules will be there and loaded, but if you are running a custom kernel they
might be built in and the error will just annoy the hell out of you :) (just
showing the opposite case of what you are asking for.. somebody will complain
that the errors are there).

Fabio

--
I'm going to make him an offer he can't refuse.

[Fabio Massimo Di Nitto (fabbione)]

All bugs marked as duplicates of this one have been reassigned to #74346 as suggested by https://wiki.ubuntu.com/StableReleaseUpdates point 1 ("If more than one bug is being addressed, it is better to file a bug to track the SRU itself and refer to all of the relevant bugs.")

This bug is still related to mdadm/evms that will not be addressed in this first fix.

Fabio

[Venkat (ubuntu-venkatp)]

ok. Thanks for the fix (Well. Almost fix) . We have been suffering from this now for three months.

In our case, we have Edgy on Software RAID which we disk cloned and use it in three other machines of the same configuration. Prior to the fix, in each cloned disk machine will take over 10 mins (same pattern. After the msg 'Mouting root file system'. screen goes blank with a blinking cursor for that 10 mins and boot resumes).

I just did apt-get update mdadm in each cloned machine (which did the update-initramfs as well as expected), the machine boot time became normal for those machines.

I went back to the original disk machine, installed the mdadm update, and did some app installs etc. Now did the cloning disk again to the other machines. On booting of the cloned disk machine, the boot still took more 10 mins. I did a update-initramfs -u in the cloned machine and rebooted. Now the boot speed is normal.

Something is still not all right with this issue. Now, altogether cloning takes about 60 minutes more for the three machines which is such a waste of time.

Do you need any more info to look into this as well?

[Fabio Massimo Di Nitto (fabbione)]

It depends how you do clone the disks. Note that the initramfs is updated on each machine for the very good reason that some raid information are stored there.

If the wrong information are cloned in the initramfs of another machine, that one will suffer of the problem again and you will need to regenerate the initramfs manually.

Fabio

[Richard Bailey (rmjb)]

This scenario is also happening to me, for me the wait can be over 10 minutes. I also use evms and have lvm2 on md in a raid 5.
I have the updated mdadm package from edgy-updates installed.

If there's any info that I can provide to help debug this issue please let me know.

[Dave Gilbert (ubuntu-treblig)]

Hi Richard,
  If you can post a copy of your /etc/mdadm.conf (or is it /etc/mdadm/mdadm.conf), the output of cat /proc/mdstat, your /etc/fstab
and an ls -l of /dev/disk/by-uuid
  that might give something to help with.

Dave

[Richard Bailey (rmjb)]

cat /etc/mdadm/mdadm.conf
DEVICE partitions

cat /proc/mdstat
Personalities : [raid5] [raid4]
md0 : active raid5 hda6[0] hdd1[2] hdc1[1]
      390700544 blocks level 5, 32k chunk, algorithm 0 [3/3] [UUU]

unused devices: <none>

cat /etc/fstab
# /etc/fstab: static file system information.
#
# <file system> <mount point> <type> <options> <dump> <pass>
proc /proc proc defaults 0 0
# /dev/hda2 -- converted during upgrade to edgy
UUID=92a0c172-7a07-47f6-9ca3-e6935cb93642 / ext3 defaults,errors=remount-ro 0 1
# /dev/hda1 -- converted during upgrade to edgy
UUID=b04c24c9-8a1c-43fa-ac79-e456cc6d437f /boot ext3 defaults 0 2
# /dev/hda5 -- converted during upgrade to edgy
UUID=b4749463-67b8-4d80-bd3b-98366fee3d4b none swap sw 0 0
/dev/hdb /media/cdrom0 udf,iso9660 user,noauto 0 0
/dev/evms/shares /mnt/shares xfs defaults 0 0
#/dev/sda1 /mnt/backup ext3 rw,noatime 0 0

ls -l /dev/disk/by-uuid
total 0
lrwxrwxrwx 1 root root 10 2007-04-02 22:23 92a0c172-7a07-47f6-9ca3-e6935cb93642 -> ../../hda2
lrwxrwxrwx 1 root root 10 2007-04-02 22:23 b04c24c9-8a1c-43fa-ac79-e456cc6d437f -> ../../hda1
lrwxrwxrwx 1 root root 10 2007-04-02 22:23 b4749463-67b8-4d80-bd3b-98366fee3d4b -> ../../hda5

Hope that helps.

[Thomas Schwinge (tschwinge)]

Having had a very similar problem (see <https://bugs.launchpad.net/ubuntu/+source/linux-source-2.6.20/+bug/74522>) which was gone after a fresh gutsy install, perhaps this does ``solve'' this issue here as well?

[ceg (ceg)]

no activity for long assuming fix released