Странные лог-сообщения от LVM и зависания сервера

На одном из наших серверов виртуализации OpenSUSE (11.3) у нас недавно были некоторые проблемы со стабильностью. Сервер довольно сильно загружен, с до 100 виртуальных доменов, все из которых работают на снимках LVM. У нас внезапно завис сервер (все еще отвечает на команду ping, невозможно войти).

Сервер записывает в журнал много сообщений от LVM, но я не уверен, нормально это или нет. Это пример журнала прямо перед зависанием сервера:

Oct 28 13:26:35 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 28 13:26:35 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 28 13:27:15 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 28 13:27:15 xen lvm[3384]: dm_task_run failed, errno = 22, Invalid argument
Oct 28 13:28:25 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 28 13:30:45 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 28 13:30:55 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 28 13:30:55 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 28 13:31:05 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 28 13:31:05 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 28 13:31:05 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 28 13:31:15 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 28 13:31:21 xen kernel: [76866.784142] ata3.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
Oct 28 13:31:21 xen kernel: [76866.784158] sr 2:0:0:0: [sr0] CDB: Get event status notification: 4a 01 00 00 10 00 00 00 08 00
Oct 28 13:31:21 xen kernel: [76866.784183] ata3.00: cmd a0/00:00:00:08:00/00:00:00:00:00/a0 tag 0 pio 16392 in
Oct 28 13:31:21 xen kernel: [76866.784186]          res 40/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
Oct 28 13:31:21 xen kernel: [76866.784192] ata3.00: status: { DRDY }
Oct 28 13:31:25 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 28 13:31:25 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 28 13:31:26 xen kernel: [76871.824061] ata3: link is slow to respond, please be patient (ready=0)
Oct 28 13:31:31 xen kernel: [76876.808057] ata3: device not ready (errno=-16), forcing hardreset
Oct 28 13:31:31 xen kernel: [76876.808080] ata3: soft resetting link
Oct 28 13:31:31 xen kernel: [76876.972455] ata3: nv_mode_filter: 0x739f&0x739f->0x739f, BIOS=0x7000 (0xc0000000) ACPI=0x701f (60:900:0x11)
Oct 28 13:31:31 xen kernel: [76876.988343] ata3.00: configured for UDMA/33
Oct 28 13:31:31 xen kernel: [76876.988971] ata3: EH complete
Oct 28 13:31:35 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 28 13:31:45 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 28 13:32:05 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 28 13:32:35 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 28 13:35:55 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 28 13:36:05 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 28 13:36:25 xen lvm[3384]: Another thread is handling an event. Waiting...

На данный момент у меня есть четыре вопроса:

  1. Эти сообщения журнала нормальны для LVM?
  2. Почему dm_task_run печатает ошибки о недопустимых аргументах в журнале?
  3. Что может вызвать сброс канала SATA?
  4. Есть ли в этом подсказка, что может привести к зависанию сервера?

Изменить: На следующем зависании я получил больше информации:

Oct 30 01:59:25 xen lvm[3384]: Another thread is handling an event. Waiting...
Oct 30 02:01:15 xen kernel: [208260.160037] BUG: soft lockup - CPU#3 stuck for 67s! [qemu-dm:12987]
Oct 30 02:01:15 xen kernel: [208260.160053] BUG: soft lockup - CPU#4 stuck for 67s! [qemu-dm:26429]
Oct 30 02:01:15 xen kernel: [208260.160070] Modules linked in:
Oct 30 02:01:15 xen kernel: [208260.160074] Modules linked in: bridge stp llc bridge usbbk stp llc gntdev usbbk gntdev netbk netbk blkbk blkbk blkback hcd usbcore sd_mod dm_snapshot xenblk ehci_hcd cdrom xennet usbcore edd dm_mod dm_snapshot fan pata_amd xenblk sata_nv libata cdrom scsi_mod thermal xennet processor thermal_sys edd hwmon
Oct 30 02:01:15 xen kernel: [208260.160276]  dm_modCPU 4
Oct 30 02:01:15 xen kernel: [208260.160283] Modules linked in: fan bridge stp pata_amd llc usbbk gntdev netbk sata_nv blkbk blkback_pagemap libata blktap domctl xenbus_be scsi_mod evtchn nfs lockd thermal fscache nfs_acl auth_rpcgss processor sunrpc fuse loop thermal_sys tg3 pcspkr i2c_nforce2 hwmon i2c_core ghes 8250_pnp
Oct 30 02:01:15 xen kernel: [208260.160342] CPU 3  8250
Oct 30 02:01:15 xen kernel: [208260.160346] Modules linked in: shpchp bridge stp llc k10temp usbbk gntdev netbk hed blkbk blkback_pagemap blktap domctl sr_mod xenbus_be evtchn nfs forcedeth pci_hotplug lockd serial_core serio_raw sg fscache nfs_acl button auth_rpcgss sunrpc fuse usbhid hid linear ohci_hcd loop sd_mod ehci_hcd tg3 pcspkr i2c_nforce2 usbcore i2c_core ghes 8250_pnp dm_snapshot 8250 shpchp k10temp xenblk hed sr_mod cdrom forcedeth xennet edd dm_mod pci_hotplug serial_core fan serio_raw sg pata_amd button usbhid hid sata_nv libata linear scsi_mod ohci_hcd sd_mod thermal ehci_hcd processor thermal_sys hwmon usbcore dm_snapshot
Oct 30 02:01:15 xen kernel: [208260.160471]  xenblk
Oct 30 02:01:15 xen kernel: [208260.160477]  cdrom

1 ответ

Решение

Единственный вопрос, на который я получил твердый ответ, - первый: это сообщение не является нормальным для моего LVM.

Поиск сообщения в Google не вызывает ничего, кроме этой темы, где у парня зависание LVM при сбое диска, где, по-видимому, lvm не может обнаружить, что диск по какой-то причине вышел из строя (дальнейшие сообщения в теме идут в это причина, но я недостаточно знаком с многолучевым распространением или SAN, чтобы понять, что происходит). Если вы не используете многолучевое распространение, это, вероятно, мало что даст для вас.

По моему опыту сброс дисков является признаком неисправного диска, но обычно отказывающие диски регистрируют множество ошибок тайм-аута, прежде чем ядро ​​решит попытаться сбросить его. Попробуйте прочитать информацию SMART для соответствующего накопителя (ей) и посмотреть, считает ли накопитель проблему? Это также может быть проблема с микропрограммой привода или контроллера, поскольку первый журнал, по-видимому, подразумевает, что диск просто внезапно перестал отвечать, но, возможно, ошибки тайм-аута были потеряны где-то перед потоком сообщений lvm. Если ata3 не новый диск, проблема с прошивкой менее вероятна. Что интересно, после сброса накопитель регистрируется в режиме UDMA/33 (старая скорость PATA), что означает, что накопитель не был сброшен правильно, что может объяснить, почему LVM оставался зависшим.

Другие вопросы по тегам