Tag Archives: compute issues

RAID-5 Horror Story – A tale of woe and notes on how to avoid a similar fate

As a starting point, since someone is sure to mention it, I KNOW THAT RAID IS NOT A BACKUP!!. On the other hand I’ve yet to meet someone who can tell me an affordable way to back up a 12TB array short of buying enough disks to clone it.

I’ve had a home-build linux md server for quite some time now. Brought the array online ~2011 and have grown it multiple times since then. It was at 7 x 2TB (apparently a bad idea all by itself, not that the software would warn you when you add the disk to the pool) disks and over the years had survived disk failures, power cuts while being grown, and 2 house moves.

Basic Setup

  • Linux MD disk array
  • 7 x 2TB 3.5″ SATA Disks
  • Whole disk (or array in this case) encryption (cryptsetup)
  • XFS Filesystem on top

Where it started to go wrong

It started, as these things usually do with an e-mail from my server, cheerfully informing me that one of the disks had died and that the raid array was degraded. Not really a problem as this had happened before without major drama.

  • Order a new disk
  • Figure out which one is /dev/sdf
    • hwinfo --disks helps a lot for this since it can get serial numbers
  • Shut the server down
  • Swap in the new disk
  • Add it to the array, and take things easy while it rebuilds (approx time required ~10 hours when disks are not being used)

And that was when I hit the dreaded Unrecoverable Read Error 🙁 Much has been written about this, but it was my first experience of it (and won’t forget it in a hurry).

[  772.229943] md: bind<sdh>
[  772.793789] RAID conf printout:
[  772.793794]  --- level:5 rd:7 wd:6
[  772.793798]  disk 0, o:1, dev:sdg
[  772.793802]  disk 1, o:1, dev:sdh
[  772.793805]  disk 2, o:1, dev:sdi
[  772.793809]  disk 3, o:1, dev:sdf
[  772.793812]  disk 4, o:1, dev:sdd
[  772.793816]  disk 5, o:1, dev:sdb
[  772.793819]  disk 6, o:1, dev:sda
[  772.794310] md: recovery of RAID array md0
[  772.794316] md: minimum _guaranteed_  speed: 1000 KB/sec/disk.
[  772.794368] md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for recovery.
[  772.794378] md: using 128k window, over a total of 1953514496k.
...
[35295.808096] ata9.00: exception Emask 0x0 SAct 0x7fffffff SErr 0x0 action 0x6 frozen
[35295.808105] ata9.00: failed command: READ FPDMA QUEUED
[35295.808116] ata9.00: cmd 60/08:00:20:01:ce/00:00:ab:00:00/40 tag 0 ncq 4096 in
[35295.808118]          res 40/00:01:00:4f:c2/00:00:00:00:00/00 Emask 0x4 (timeout)
[35295.808124] ata9.00: status: { DRDY }
[35397.139031] sd 8:0:0:0: [sdf]  Add. Sense: Unrecovered read error - auto reallocate failed
[35397.139041] sd 8:0:0:0: [sdf] CDB: Read(10): 28 00 ab cd f8 58 00 03 08 00
[35397.139057] end_request: I/O error, dev sdf, sector 2882403160
[35397.139066] md/raid:md0: read error not correctable (sector 2882403160 on sdf).
[35397.139073] md/raid:md0: Disk failure on sdf, disabling device.
[35397.139075] md/raid:md0: Operation continuing on 5 devices.
[35397.139116] ata9: EH complete
[35397.708320] md: md0: recovery done.
[35397.822385] RAID conf printout:
[35397.822391]  --- level:5 rd:7 wd:5
[35397.822397]  disk 0, o:1, dev:sdg
[35397.822401]  disk 1, o:1, dev:sdh
[35397.822405]  disk 2, o:1, dev:sdi
[35397.822409]  disk 3, o:0, dev:sdf
[35397.822412]  disk 4, o:1, dev:sdd
[35397.822416]  disk 5, o:1, dev:sdb
[35397.822419]  disk 6, o:1, dev:sda
[35397.824183] RAID conf printout:
[35397.824188]  --- level:5 rd:7 wd:5
[35397.824191]  disk 0, o:1, dev:sdg
[35397.824195]  disk 2, o:1, dev:sdi
[35397.824198]  disk 3, o:0, dev:sdf
[35397.824201]  disk 4, o:1, dev:sdd
[35397.824205]  disk 5, o:1, dev:sdb
[35397.824208]  disk 6, o:1, dev:sda
[35397.824218] RAID conf printout:
[35397.824221]  --- level:5 rd:7 wd:5
[35397.824224]  disk 0, o:1, dev:sdg
[35397.824228]  disk 2, o:1, dev:sdi
[35397.824231]  disk 3, o:0, dev:sdf
[35397.824234]  disk 4, o:1, dev:sdd
[35397.824237]  disk 5, o:1, dev:sdb
[35397.824240]  disk 6, o:1, dev:sda
[35397.824380] RAID conf printout:
[35397.824386]  --- level:5 rd:7 wd:5
[35397.824390]  disk 0, o:1, dev:sdg
[35397.824394]  disk 2, o:1, dev:sdi
[35397.824398]  disk 4, o:1, dev:sdd
[35397.824401]  disk 5, o:1, dev:sdb
[35397.824404]  disk 6, o:1, dev:sda

At which point the array is basically dead. Which seems a bit insane – read error in one sector makes 12TB of data unavailable but there you go. We apparently can’t mount, rebuild or do anything – bear in mind that at this point all our data is still intact, except for that one dodgy sector. Looking at the raid array in more detail (it is a mess):

[~]=> sudo mdadm --detail /dev/md0
/dev/md0:
        Version : 0.90
  Creation Time : Mon May 16 22:34:59 2011
     Raid Level : raid5
  Used Dev Size : 1953514496 (1863.02 GiB 2000.40 GB)
   Raid Devices : 7
  Total Devices : 5
Preferred Minor : 0
    Persistence : Superblock is persistent

    Update Time : Wed Apr 29 12:28:08 2015
          State : active, FAILED, Not Started 
 Active Devices : 4
Working Devices : 5
 Failed Devices : 0
  Spare Devices : 1

         Layout : left-symmetric
     Chunk Size : 64K

           UUID : 4a3bba9b:8299bd9b:3cb2199d:f2060f75
         Events : 0.1434672

    Number   Major   Minor   RaidDevice State
       0       8       96        0      active sync   /dev/sdg
       1       0        0        1      removed
       2       8      128        2      active sync   /dev/sdi
       3       0        0        3      removed
       4       8       48        4      active sync   /dev/sdd
       5       8       16        5      active sync   /dev/sdb
       6       0        0        6      removed

       7       8      112        -      spare   /dev/sdh

Pay close attention to the metadata version – this is where I went horribly wrong (more on that later). From the list of disks we have /dev/sdf removed automatically due to the read error and /dev/sdh in as a spare since it was in the process of being synced when everything went pear shaped.

Steps to recovery

At this point I was quite annoyed and a bit desperate so I concocted a plan that would have worked, but for one mistake. My plan was simple

  1. Remove /dev/sdh from the md0 set – it’s basically useless now anyway
  2. Get /dev/sdf back in by recreating the array
  3. Run XFS checks on the file system to be sure that is ok
  4. Use gddrescue to clone the slightly dodgy /dev/sdf to /dev/sdh – with multiple retries to try and get the problem sector
  5. Reassemble the array using /dev/sdh rather then /dev/sdf
  6. Buy another new disk and slot it in and hope the rebuild works this time
  7. Low level format /dev/sdf to get the sector marked as bad. If that fails, bin it.
  8. Convert to RAID-6 so this can’t happen again

Step 1 went as expected:

[~]=> sudo mdadm --remove /dev/md0 /dev/sdh
mdadm: hot removed /dev/sdh from /dev/md0
[~]=> sudo mdadm --detail /dev/md0
/dev/md0:
        Version : 0.90
  Creation Time : Mon May 16 22:34:59 2011
     Raid Level : raid5
  Used Dev Size : 1953514496 (1863.02 GiB 2000.40 GB)
   Raid Devices : 7
  Total Devices : 5
Preferred Minor : 0
    Persistence : Superblock is persistent

    Update Time : Wed Apr 29 12:41:58 2015
          State : active, FAILED, Not Started 
 Active Devices : 5
Working Devices : 5
 Failed Devices : 0
  Spare Devices : 0

         Layout : left-symmetric
     Chunk Size : 64K

           UUID : 4a3bba9b:8299bd9b:3cb2199d:f2060f75
         Events : 0.1434673

    Number   Major   Minor   RaidDevice State
       0       8       96        0      active sync   /dev/sdg
       1       0        0        1      removed
       2       8      128        2      active sync   /dev/sdi
       3       8       80        3      removed
       4       8       48        4      active sync   /dev/sdd
       5       8       16        5      active sync   /dev/sdb
       6       8        0        6      active sync   /dev/sda

So I decided to re-create the array rather then re-assemble (with assume-clean), and here I went very wrong. I didn’t specify the metadata version.

MD RAID Metadata Versions

It used to be the default format of raid superblock during array creation on most distributions until 2009, the older version-0.90 superblock format had several limitations that limited its applicability for use on large arrays or arrays with many component devices.

The version-0.90 superblock limits the number of component devices within an array to 28, and limits each component device to a maximum size of 2TB on kernel version <3.1 and 4TB on kernel version >=3.1.

The superblock is 4K long and is written into a 64K aligned block that starts at least 64K and less than 128K from the end of the device (i.e. to get the address of the superblock round the size of the device down to a multiple of 64K and then subtract 64K). The available size of each device is the amount of space before the super block, so between 64K and 128K is lost when a device in incorporated into an MD array.

Also, and this is important – it is stored at the end of the device. If you want mdadm to use this you have to specify –metadata=0.9

The shiny new (and now the default) is version 1.2 which grabs 4K from the beginning of the device, and while doing so torches the XFS superblock.

XFS Gone

When I realised my mistake, got the drives into a sort of working order, and mounted, I was presented with

[~]=> sudo mount /dev/mapper/storage /mnt/storage
mount: /dev/mapper/storage: can't read superblock

From our message log

[ 1337.665651] SGI XFS with ACLs, security attributes, realtime, large block/inode numbers, no debug enabled
[ 1337.666154] SGI XFS Quota Management subsystem
[ 1337.666931] XFS (dm-3): Mounting Filesystem
[ 1339.452417] XFS (dm-3): Log inconsistent (didn't find previous header)
[ 1339.452441] XFS (dm-3): failed to find log head
[ 1339.452447] XFS (dm-3): log mount/recovery failed: error 5
[ 1339.452524] XFS (dm-3): log mount failed

xfs_repair, after throwing around many dots seemed to be completely unhappy with any of the secondary superblocks, and UFS Recover could only re-assemble some bits and pieces.

And that was the end of that.

Lessons learned

  • Never more the 4 devices in RAID-5
  • Always make a backup
  • Be very very careful when trying to repair
  • For tools that have been in service for longer then a few months, be very very careful. Some idiot developer has probably changed the defaults in a way that will screw you

OpenStack Nova Upgrade & RabbitMQ

I had occasion to upgrade my Contrail cluster from 1.03 -> 1.04. While this was hampered by network issues in the lab (the witch hunt for the guilty party messing with cables is ongoing) I came out of it with a problem on one of the two compute hosts (the working one wasn’t upgraded due to the network issue).

/var/log/nova/compute.log provided this little gem:

2014-04-03 14:36:38.068 ERROR nova.openstack.common.rpc.impl_qpid [req-9becc8bb-e75a-4700-b289-a188a98a2645 None None] Unable to connect to AMQP server: client: 0-10, server: 9-1. Sleeping 60 seconds

As I understand it, RabbitMQ only supports 0-9-1 (running on the controller), but it looks like the client (vRouter side) is running 0-10-0 (QPID) – these are not compatible. Turns out on that the OpenStack side openstack-nova-compute was now configured to use QPID rather then RabbitMQ:

rpc_backend = nova.openstack.common.rpc.impl_qpid
...
qpid_hostname = x.y.x.230

Edit /etc/nova/nova.conf to have:

rpc_backend = nova.openstack.common.rpc.impl_kombu
...
rabbit_host = x.y.x.230

and restart the openstack-nova-compute service and we are in business.

Something else worth noting is that if you switch the RPC backend and start getting:

2014-04-04 13:26:28.659 ERROR nova.openstack.common.rpc.common [req-f0ea9acc-f6e0-46e2-81f6-1e4b23f0bd2a None None] AMQP server on localhost:5672 is unreachable: [Errno 111] ECONNREFUSED. Trying again in 15 seconds.

in your log (multi-node setup here with separate messaging server) then you have made the mistake, as I did, of assuming that the rabbit_host at the end of the file is parsed – it isn’t! Make sure your configuration is before the [keystone_authtoken] block e.g.

volume_api_class = nova.volume.cinder.API
enabled_apis=ec2,osapi_compute,metadata
auth_strategy=keystone
#qpid_hostname = x.y.z.230
glance_host = x.y.z.230
quantum_url_timeout = 300
novncproxy_base_url = http://10.3.8.230:5999/vnc_auto.html
vncserver_enabled = true
vncserver_listen = x.y.z.231
vncserver_proxyclient_address = x.y.z.231
security_group_api = quantum
heal_instance_info_cache_interval = 0
libvirt_cpu_mode = none
rabbit_host = x.y.z.230


[keystone_authtoken]
admin_tenant_name = service
admin_user = nova
admin_password = 154c7f845c59fe7b9a78
auth_host = x.y.z.230
auth_port = 35357
auth_protocol = http
signing_dir = /tmp/keystone-signing-nova

Checking the current version of Nova

It seems there is nothing along the lines of /etc/release to tell us what version of nova-compute we are actually running, but you can extract the required information. On the compute host:

[root@compute-1 ~]# nova-manage shell python
Python 2.6.6 (r266:84292, Jan 22 2014, 09:42:36)
[GCC 4.4.7 20120313 (Red Hat 4.4.7-4)] on linux2
Type "help", "copyright", "credits" or "license" for more information.
(InteractiveConsole)
>>> from nova import version
>>> version.version_string()
'2013.1'
>>>

One Step Forward and Two Steps Sideways

A day of challenges and frustrations today

some as a result of my own carelessness, others because of the nature of a shared lab environment, and others still because technology hates us sometimes

A slow but steady start – sometimes the nested hypervisor matters

My aim was to get Contrail/OpenStack running for some testing today. Given that I don’t have a few baremetal servers lying around, I did what most people do, and decided to run my hosts on VMware (great tool). This can occasionally cause issues as I discovered later, but is great to get a few machines up and running in a hurry. I don’t really have issue with the idea of running Cloud Computing services on a virtualised environment, though a few did roll their eyes 🙂

I decided (having previously played with single-node installation) to go for a 3 machine setup, 2 compute nodes and 1 controller/openstack services. The reason for this was to have the compute hosts on physically separated machines to allow me to capture wire traffic between VMs and get a feel for the underlay networking and test some things there. Initial install went smoothly, as did installation of images onto Glance – word to the wise, make sure you have a large enough partition for the images! I ended up having to add a new partition to store a large image:

Filesystem Size Used Avail Use% Mounted on
/dev/mapper/VolGroup-lv_root
12G   5.5G 5.6G 50%   /
tmpfs     12G   0    12G   0%   /dev/shm
/dev/sda1 485M  37M  423M  9%   /boot
/dev/sdb1 30G   7.2G 21G  26%   /mnt/glance-storage

Stopping glance, copying the contents across to /mnt/glance-storage and editing /etc/glance/glance-api.conf to point to the new location, followed by restarting glance.

# ============ Filesystem Store Options ========================
#Directory that the Filesystem backend store
# writes image data to
filesystem_store_datadir = /mnt/glance-storage/

Large images enabled I then tried to fire up a tiny CIRROS image, to no avail. Fortunately, and surprisingly, /var/log/nova/conpute.log (on the compute node) offered a clue:

libvirtError: internal error no supported architecture for os type ‘hvm’

This rather helpful error indicates that the libvirt through which we control the OpenStack hypervisor is not available to run. Contrail aims to use KVM as the default hypervisor, though getting KVM to run when the base OS is hosted on ESXi requires a little more attention then I expected – next post. As a quick workaround, I simply told nova to use QEMU instead by modifying /etc/nova/nova.conf and specifying the libvirt type.

network_api_class = nova.network.quantumv2.api.API
libvirt_vif_driver = contrail_vif.contrailvif.VRouterVIFDriver
libvirt_type=qemu

A quick restart of nova services and we were in business 🙂 or so I thought

The attack of the larger then m1.tiny instance

OpenStack has the concept of virtual machine flavors – these essentially define the capacity of a VM in terms of CPU, Memory, Disk Space, etc.

The default flavors are:

  • m1.tiny (1 VCPU/0 GB Disk/512 MB RAM)
  • m1.small (1 VCPU/20 GB Disk/2048 MB RAM)
  • m1.medium (2 VCPU/40 GB Disk/4096 MB RAM)
  • m1.large (4 VCPU/80 GB Disk/8192 MB RAM)
  • m1.xlarge (8 VCPU/160 GB Disk/16384 MB RAM)

Imagine my surprise when it turned out that only a tiny instance could be booted. In the end the cause was obvious, in that the flavors causing issues were those allocated disk space.
The compute hosts require sufficient local storage to hold the virtual machine disk space (root and ephemeral – this is not the VM image in glance e.g. the OS) for all their running instances. This was a problem as I just allocated initial disks of ~24Gb to my compute hosts (datastore space can be limited in a shared lab, and wars have been fought over less).

Nova (compute service) actually stashes the running disk images in /var/lib/nova/instances/<instance-id>. The parameter which I think governs this path is set in /etc/nova/nova.conf  (I believe this to be state_path = /var/lib/nova though the documentation is fuzzy on that) though rumours reached me that very bad things happen to those who play with the paths in nova.conf 🙁

Apparently the preferred approach is to create a huge local disk partition (or just allocated a big disk) and mount it at /var/lib/nova – so that’s what I did

Filesystem Size Used Avail Use% Mounted on
/dev/mapper/VolGroup-lv_root
12G  3.5G 7.5G  32%  /
tmpfs      12G  0    12G   0%   /dev/shm
/dev/sda1  485M 37M  423M  9%   /boot
/dev/sdb1  99G  4.2G 90G   5%   /var/lib/nova

And added it into /etc/fstab so it survives the many reboots that a lab requires

/dev/sdb1 /var/lib/nova ext3 defaults 1 2

And with that instances of all sizes could roam freely 🙂

More on getting KVM working as the hypervisor in the next post!