[sisyphus] xfs or disk ?

[sisyphus] xfs or disk ?

[Alexey Morsov]

[-- Attachment #1: Type: text/plain, Size: 4551 bytes --]

Сегодня уже пару раз наблюдал такую картину. Внезапно (хихи) перестает
читаться один диск (на весь диск одна партиция). Причем на компе горит
лампочка активности диска но ее нет (судя по iotop). Файлы не читаются
директории видны но в них ничего нет. Ну вообщем бред. Партиция при этом
замонтирована. df отрабатывает.

После перезагрузки все в норме, все на месте xfs_check ничего не выдает.
В логах такое:

Sep 18 15:57:47 home kernel: [57344.507703] xfs_force_shutdown(sdb1,0x2) called from line 1043 of file fs/xfs/xfs_log.c.  Return address = 0xffffffffa02eb863
Sep 18 15:58:03 home kernel: [57360.704011] Filesystem "sdb1": xfs_log_force: error 5 returned.
Sep 18 15:58:39 home kernel: [57396.704011] Filesystem "sdb1": xfs_log_force: error 5 returned.
Sep 18 15:59:15 home kernel: [57432.704013] Filesystem "sdb1": xfs_log_force: error 5 returned.
Sep 18 15:59:51 home kernel: [57468.704010] Filesystem "sdb1": xfs_log_force: error 5 returned.
Sep 18 16:00:27 home kernel: [57504.704011] Filesystem "sdb1": xfs_log_force: error 5 returned.
Sep 18 16:00:43 home kernel: [57520.804228] xfs_force_shutdown(sdb1,0x1) called from line 335 of file fs/xfs/xfs_rw.c.  Return address = 0xffffffffa030038b
Sep 18 16:00:43 home kernel: [57520.820203] xfs_force_shutdown(sdb1,0x1) called from line 335 of file fs/xfs/xfs_rw.c.  Return address = 0xffffffffa030038b
Sep 18 16:00:43 home kernel: [57521.196983] Filesystem "sdb1": xfs_log_force: error 5 returned.
Sep 18 16:00:43 home kernel: [57521.198112] Filesystem "sdb1": xfs_log_force: error 5 returned.
Sep 18 17:16:11 home kernel: [ 4349.908172] I/O error in filesystem ("sdb1") meta-data dev sdb1 block 0x868850       ("xfs_trans_read_buf") error 5 buf count 8192
Sep 18 17:16:11 home kernel: [ 4349.908176] xfs_imap_to_bp: xfs_trans_read_buf()returned an error 5 on sdb1.  Returning error.
Sep 18 17:16:11 home kernel: [ 4349.908415] I/O error in filesystem ("sdb1") meta-data dev sdb1 block 0x868850       ("xfs_trans_read_buf") error 5 buf count 8192
Sep 18 17:16:11 home kernel: [ 4349.908417] xfs_imap_to_bp: xfs_trans_read_buf()returned an error 5 on sdb1.  Returning error.
Sep 18 17:16:11 home kernel: [ 4349.908458] I/O error in filesystem ("sdb1") meta-data dev sdb1 block 0x868850       ("xfs_trans_read_buf") error 5 buf count 8192
Sep 18 17:16:11 home kernel: [ 4349.908460] xfs_imap_to_bp: xfs_trans_read_buf()returned an error 5 on sdb1.  Returning error.
Sep 18 17:16:11 home kernel: [ 4349.908498] I/O error in filesystem ("sdb1") meta-data dev sdb1 block 0x868850       ("xfs_trans_read_buf") error 5 buf count 8192
Sep 18 17:16:11 home kernel: [ 4349.908506] xfs_imap_to_bp: xfs_trans_read_buf()returned an error 5 on sdb1.  Returning error.
Sep 18 17:16:11 home kernel: [ 4349.908557] I/O error in filesystem ("sdb1") meta-data dev sdb1 block 0x868850       ("xfs_trans_read_buf") error 5 buf count 8192
Sep 18 17:16:11 home kernel: [ 4349.908561] xfs_imap_to_bp: xfs_trans_read_buf()returned an error 5 on sdb1.  Returning error.
Sep 18 17:17:46 home kernel: [ 4444.821022] xfs_force_shutdown(sdb1,0x1) called from line 335 of file fs/xfs/xfs_rw.c.  Return address = 0xffffffffa030838b
Sep 18 17:17:46 home kernel: [ 4444.852084] xfs_force_shutdown(sdb1,0x1) called from line 335 of file fs/xfs/xfs_rw.c.  Return address = 0xffffffffa030838b
Sep 18 17:17:46 home kernel: [ 4444.873715] Filesystem "sdb1": xfs_log_force: error 5 returned.


smartctl вроде тоже пишет PASSED
morsov@home ~ $ uname -a
Linux home.ru 2.6.32-un-def-alt20 #1 SMP PREEMPT Sun Aug 22 05:45:47 UTC 2010 x86_64 GNU/Linux

диск сата wd WDC WD5000AAKS-00YGA0

Это что-то с дровами файлухой или таки дисочек примеряет белые тапки?

-- 
WBR,Алексей Морсов
программист ЗАО "ИК "Риком-Траст"
Jabber: samurai@www.fondmarket.ru
ALT Linux Team Member

> хмм, слака тоже очень сильный дистрибутив. и безопасней.
[...]
> а я сижу почему-то под альтами.
"...в пустом readonly chroot псевдопользователем..." (+vserver :)
		-- mike in smoke-room@

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 490 bytes --]

Re: [sisyphus] xfs or disk ?

[Sergey Vlasov]

[-- Attachment #1: Type: text/plain, Size: 1850 bytes --]

On Sat, Sep 18, 2010 at 05:41:45PM +0400, Alexey Morsov wrote:
> Сегодня уже пару раз наблюдал такую картину. Внезапно (хихи) перестает
> читаться один диск (на весь диск одна партиция). Причем на компе горит
> лампочка активности диска но ее нет (судя по iotop). Файлы не читаются
> директории видны но в них ничего нет. Ну вообщем бред. Партиция при этом
> замонтирована. df отрабатывает.
> 
> После перезагрузки все в норме, все на месте xfs_check ничего не выдает.
> В логах такое:
> 
> Sep 18 15:57:47 home kernel: [57344.507703] xfs_force_shutdown(sdb1,0x2) called from line 1043 of file fs/xfs/xfs_log.c.  Return address = 0xffffffffa02eb863
[...]

Это реакция xfs на невозможность записи в журнал; перед этим должны
быть ещё сообщения об ошибках диска (ataN: ...) - надо смотреть их.

> smartctl вроде тоже пишет PASSED

Общий статус SMART обычно меняется, когда количество нечитаемых
секторов на диске уже исчисляется тысячами.  Надо смотреть в выводе
smartctl -A значения отдельных атрибутов (в частности, в атрибутах
Reallocated_Sector_Ct, Reallocated_Event_Count, Current_Pending_Sector
в поле RAW_VALUE в идеальном случае должен быть 0); ещё стоит
заглянуть в журнал ошибок (smartctl -l xerror,error).

> morsov@home ~ $ uname -a
> Linux home.ru 2.6.32-un-def-alt20 #1 SMP PREEMPT Sun Aug 22 05:45:47 UTC 2010 x86_64 GNU/Linux
> 
> диск сата wd WDC WD5000AAKS-00YGA0
> 
> Это что-то с дровами файлухой или таки дисочек примеряет белые тапки?

Ошибка явно уровнем ниже ФС - помимо самого диска, теоретически может
глючить контроллер, также может быть связано с плохим SATA-кабелем или
отваливающимися разъёмами.

Плохой кабель, кроме всего прочего, проявляется в атрибутах SMART
растущим счётчиком UDMA_CRC_Error_Count; некоторые диски поддерживают
более детальную статистику (smartctl -l sataphy).

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 198 bytes --]

Re: [sisyphus] xfs or disk ?

[Alexey Morsov]

[-- Attachment #1: Type: text/plain, Size: 3952 bytes --]

On Sat, Sep 18, 2010 at 06:32:26PM +0400, Sergey Vlasov wrote:
> On Sat, Sep 18, 2010 at 05:41:45PM +0400, Alexey Morsov wrote:
> Это реакция xfs на невозможность записи в журнал; перед этим должны
> быть ещё сообщения об ошибках диска (ataN: ...) - надо смотреть их.
в messages никаких error на счет ata не вижу o_O

> 
> > smartctl вроде тоже пишет PASSED
> 
> Общий статус SMART обычно меняется, когда количество нечитаемых
> секторов на диске уже исчисляется тысячами.  Надо смотреть в выводе
> smartctl -A значения отдельных атрибутов (в частности, в атрибутах
> Reallocated_Sector_Ct, Reallocated_Event_Count, Current_Pending_Sector
> в поле RAW_VALUE в идеальном случае должен быть 0); ещё стоит
> заглянуть в журнал ошибок (smartctl -l xerror,error).
  5 Reallocated_Sector_Ct   0x0033   200   200   140    Pre-fail  Always
  -       0
  196 Reallocated_Event_Count 0x0032   200   200   000    Old_age   Always
  -       0

  smartctl -l xerror,error - No Errors Logged

> 
> > morsov@home ~ $ uname -a
> > Linux home.ru 2.6.32-un-def-alt20 #1 SMP PREEMPT Sun Aug 22 05:45:47 UTC 2010 x86_64 GNU/Linux
> > 
> > диск сата wd WDC WD5000AAKS-00YGA0
> > 
> > Это что-то с дровами файлухой или таки дисочек примеряет белые тапки?
> 
> Ошибка явно уровнем ниже ФС - помимо самого диска, теоретически может
> глючить контроллер, также может быть связано с плохим SATA-кабелем или
> отваливающимися разъёмами.
Контроллер врядли. На нем висит еще один диск - основной (на нем вся
система включая /home). С ним проблем нет.

А вот кабель... есть у меня запаска - проверим.

> 
> Плохой кабель, кроме всего прочего, проявляется в атрибутах SMART
> растущим счётчиком UDMA_CRC_Error_Count; некоторые диски поддерживают
> более детальную статистику (smartctl -l sataphy).

сейчас на 2.6.35-un-def-alt4.2, вроде больше не проявляется...
в 
morsov@home ~ $ sudo smartctl -l sataphy /dev/sdb1
smartctl 5.39.1 2010-01-28 r3054 [x86_64-alt-linux-gnu] (ALT Linux
5.39.1-alt1)
Copyright (C) 2002-10 by Bruce Allen, http://smartmontools.sourceforge.net

General Purpose Logging (GPL) feature set supported
SATA Phy Event Counters (GP Log 0x11)
ID      Size     Value  Description
0x0001  2            0  Command failed due to ICRC error
0x0002  2            0  R_ERR response for data FIS
0x0003  2            0  R_ERR response for device-to-host data FIS
0x0004  2            0  R_ERR response for host-to-device data FIS
0x0005  2            0  R_ERR response for non-data FIS
0x0006  2            0  R_ERR response for device-to-host non-data FIS
0x0007  2            0  R_ERR response for host-to-device non-data FIS
0x000a  2            3  Device-to-host register FISes sent due to a
COMRESET
0x8000  4        10842  Vendor specific


Будем следить. Спасибо за советы.


-- 
WBR,Алексей Морсов
программист ЗАО "ИК "Риком-Траст"
Jabber: samurai@www.fondmarket.ru
ALT Linux Team Member

<Pilot> программы, установленные с помощью cp, нужно удалять с помощью rm

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 490 bytes --]

Re: [sisyphus] xfs or disk ?

[Sergey Vlasov]

[-- Attachment #1: Type: text/plain, Size: 501 bytes --]

On Sat, Sep 18, 2010 at 08:35:00PM +0400, Alexey Morsov wrote:
> On Sat, Sep 18, 2010 at 06:32:26PM +0400, Sergey Vlasov wrote:
> > On Sat, Sep 18, 2010 at 05:41:45PM +0400, Alexey Morsov wrote:
> > Это реакция xfs на невозможность записи в журнал; перед этим должны
> > быть ещё сообщения об ошибках диска (ataN: ...) - надо смотреть их.
> в messages никаких error на счет ata не вижу o_O

Посмотрите ещё в /var/log/kernel/* (но там придётся выбирать куски из
нескольких файлов по времени).

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 198 bytes --]

Re: [sisyphus] xfs or disk ?

[Alexey Morsov]

[-- Attachment #1: Type: text/plain, Size: 4276 bytes --]

On Sat, Sep 18, 2010 at 09:57:59PM +0400, Sergey Vlasov wrote:
 
> Посмотрите ещё в /var/log/kernel/* (но там придётся выбирать куски из
> нескольких файлов по времени).

Вот опять. В messages
Sep 19 16:11:03 home kernel: [ 4990.880025] ata2.00: exception Emask 0x0
SAct 0x0 SErr 0x0 action 0x6 frozen
Sep 19 16:11:03 home kernel: [ 4990.880030] ata2.00: failed command: READ
DMA EXT
Sep 19 16:11:03 home kernel: [ 4990.880036] ata2.00: cmd
25/00:00:a7:b1:d1/00:01:18:00:00/e0 tag 0 dma 131072 in
Sep 19 16:11:03 home kernel: [ 4990.880037]          res
40/00:00:01:4f:c2/00:00:00:00:00/00 Emask 0x4 (timeout)
Sep 19 16:11:03 home kernel: [ 4990.880040] ata2.00: status: { DRDY }
Sep 19 16:11:03 home kernel: [ 4990.880047] ata2: hard resetting link
Sep 19 16:11:08 home kernel: [ 4996.396010] ata2: link is slow to respond,
please be patient (ready=0)
Sep 19 16:11:13 home kernel: [ 5000.932009] ata2: SRST failed (errno=-16)
Sep 19 16:11:13 home kernel: [ 5000.932015] ata2: hard resetting link
Sep 19 16:11:19 home kernel: [ 5006.448009] ata2: link is slow to respond,
please be patient (ready=0)
Sep 19 16:11:23 home kernel: [ 5010.984010] ata2: SRST failed (errno=-16)
Sep 19 16:11:23 home kernel: [ 5010.984016] ata2: hard resetting link
Sep 19 16:11:29 home kernel: [ 5016.500010] ata2: link is slow to respond,
please be patient (ready=0)
Sep 19 16:11:58 home kernel: [ 5046.012010] ata2: SRST failed (errno=-16)
Sep 19 16:11:58 home kernel: [ 5046.012016] ata2: limiting SATA link speed
to 1.5 Gbps
Sep 19 16:11:58 home kernel: [ 5046.012021] ata2: hard resetting link
Sep 19 16:12:03 home kernel: [ 5051.024010] ata2: SRST failed (errno=-16)
Sep 19 16:12:03 home kernel: [ 5051.024014] ata2: reset failed, giving up
Sep 19 16:12:03 home kernel: [ 5051.024017] ata2.00: disabled
Sep 19 16:12:03 home kernel: [ 5051.024027] ata2: EH complete
Sep 19 16:12:03 home kernel: [ 5051.024040] sd 1:0:0:0: [sdb] Unhandled
error code
Sep 19 16:12:03 home kernel: [ 5051.024042] sd 1:0:0:0: [sdb] Result:
hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK
Sep 19 16:12:03 home kernel: [ 5051.024046] sd 1:0:0:0: [sdb] CDB:
Read(10): 28 00 18 d1 b1 a7 00 01 00 00
Sep 19 16:12:03 home kernel: [ 5051.024057] end_request: I/O error, dev
sdb, sector 416395687


в kernel/errors

Sep 19 16:11:03 home kernel: [ 4990.880025] ata2.00: exception Emask 0x0
SAct 0x0 SErr 0x0 action 0x6 frozen
Sep 19 16:11:03 home kernel: [ 4990.880030] ata2.00: failed command: READ
DMA EXT
Sep 19 16:11:03 home kernel: [ 4990.880036] ata2.00: cmd
25/00:00:a7:b1:d1/00:01:18:00:00/e0 tag 0 dma 131072 in
Sep 19 16:11:03 home kernel: [ 4990.880037]          res
40/00:00:01:4f:c2/00:00:00:00:00/00 Emask 0x4 (timeout)
Sep 19 16:11:03 home kernel: [ 4990.880040] ata2.00: status: { DRDY }
Sep 19 16:11:13 home kernel: [ 5000.932009] ata2: SRST failed (errno=-16)
Sep 19 16:11:23 home kernel: [ 5010.984010] ata2: SRST failed (errno=-16)
Sep 19 16:11:58 home kernel: [ 5046.012010] ata2: SRST failed (errno=-16)
Sep 19 16:12:03 home kernel: [ 5051.024010] ata2: SRST failed (errno=-16)
Sep 19 16:12:03 home kernel: [ 5051.024014] ata2: reset failed, giving up
Sep 19 16:12:03 home kernel: [ 5051.024057] end_request: I/O error, dev
sdb, sector 416395687
Sep 19 16:13:01 home kernel: [ 5109.090969] end_request: I/O error, dev
sdb, sector 416395943
Sep 19 16:13:01 home kernel: [ 5109.090991] end_request: I/O error, dev
sdb, sector 574578719


При этом smartctl --all
 
Short INQUIRY response, skip product id
A mandatory SMART command failed: exiting. To continue, add one or more
'-T permissive' options.

-- 
WBR,Алексей Морсов
программист ЗАО "ИК "Риком-Траст"
Jabber: samurai@www.fondmarket.ru
ALT Linux Team Member

<AMorozov> vsu: то есть, я правильно понял, что ваше отношение к
           tmpfs-lookup-traps в данный момент отрицательное?
<vsu> AMorozov: по крайней мере места, напоминающие баги, там есть
<AMorozov> vsu: :-) Удивительная политкорректность ;-)

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 490 bytes --]