mptscsih: ioc0: attempting task abort!
Bonjour tout le monde,
Puis-je vous demander vos avis sur le phénomène suivant ?
Mercredi, mdadm me signale coup sur coup que les trois partitions d'un
même disque ont été éjectées de leurs arrays raid.
Dans le syslog du moment, il y a ceci :
Apr 7 12:17:01 kelsen /USR/SBIN/CRON[31528]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
Apr 7 12:49:31 kelsen kernel: [470074.816038] mptscsih: ioc0: attempting task abort! (sc=ffff88007c090580)
Apr 7 12:49:31 kelsen kernel: [470074.831961] sd 0:0:3:0: [sdd] CDB: Write(10): 2a 00 04 79 e5 6b 00 00 18 00
Apr 7 12:49:35 kelsen kernel: [470079.345585] mptbase: ioc0: LogInfo(0x31140000): Originator={PL}, Code={IO Executed}, SubCode(0x0000)
Apr 7 12:49:35 kelsen kernel: [470079.365839] mptscsih: ioc0: task abort: SUCCESS (sc=ffff88007c090580)
Apr 7 12:49:41 kelsen kernel: [470085.345723] mptbase: ioc0: LogInfo(0x3112011a): Originator={PL}, Code={Abort}, SubCode(0x011a)
Apr 7 12:49:41 kelsen kernel: [470085.366051] mptbase: ioc0: LogInfo(0x3112011a): Originator={PL}, Code={Abort}, SubCode(0x011a)
Apr 7 12:49:41 kelsen kernel: [470085.366056] mptscsih: ioc0: attempting task abort! (sc=ffff88007ac8ecc0)
Apr 7 12:49:41 kelsen kernel: [470085.366059] sd 0:0:3:0: [sdd] CDB: Write(10): 2a 00 07 4d 8b 43 00 00 08 00
Apr 7 12:49:41 kelsen kernel: [470085.424450] mptbase: ioc0: LogInfo(0x3112011a): Originator={PL}, Code={Abort}, SubCode(0x011a)
Apr 7 12:49:41 kelsen kernel: [470085.445921] mptbase: ioc0: LogInfo(0x3112011a): Originator={PL}, Code={Abort}, SubCode(0x011a)
Apr 7 12:49:41 kelsen kernel: [470085.467397] mptscsih: ioc0: task abort: SUCCESS (sc=ffff88007ac8ecc0)
Apr 7 12:49:42 kelsen kernel: [470085.486975] mptscsih: ioc0: attempting task abort! (sc=ffff88007ac8e9c0)
Apr 7 12:49:42 kelsen kernel: [470085.507242] sd 0:0:3:0: [sdd] CDB: Write(10): 2a 00 07 4d 96 a3 00 00 08 00
Apr 7 12:49:42 kelsen kernel: [470085.507249] mptscsih: ioc0: task abort: FAILED (sc=ffff88007ac8e9c0)
Apr 7 12:49:42 kelsen kernel: [470085.507251] mptscsih: ioc0: attempting task abort! (sc=ffff88007ac8e8c0)
Apr 7 12:49:42 kelsen kernel: [470085.507253] sd 0:0:3:0: [sdd] CDB: Write(10): 2a 00 07 4d 9a 03 00 00 08 00
Apr 7 12:49:42 kelsen kernel: [470085.507260] mptscsih: ioc0: task abort: FAILED (sc=ffff88007ac8e8c0)
Apr 7 12:49:42 kelsen kernel: [470085.507264] mptscsih: ioc0: attempting target reset! (sc=ffff88007c090580)
Apr 7 12:49:42 kelsen kernel: [470085.507266] sd 0:0:3:0: [sdd] CDB: Write(10): 2a 00 04 79 e5 6b 00 00 18 00
Apr 7 12:49:42 kelsen kernel: [470085.514421] mptscsih: ioc0: target reset: SUCCESS (sc=ffff88007c090580)
Apr 7 12:49:42 kelsen kernel: [470085.514425] mptscsih: ioc0: attempting bus reset! (sc=ffff88007c090580)
Apr 7 12:49:42 kelsen kernel: [470085.514426] sd 0:0:3:0: [sdd] CDB: Write(10): 2a 00 04 79 e5 6b 00 00 18 00
Apr 7 12:49:42 kelsen kernel: [470086.127249] mptscsih: ioc0: bus reset: SUCCESS (sc=ffff88007c090580)
Apr 7 12:49:42 kelsen kernel: [470086.389783] mptbase: ioc0: LogInfo(0x30030501): Originator={IOP}, Code={Invalid Page}, SubCode(0x0501)
[ligne ci-dessus répétée 11 fois ]
Apr 7 12:49:54 kelsen kernel: [470086.712337] end_device-0:3: mptsas: ioc0: removing ssp device: fw_channel 0, fw_id 9, phy 3,sas_addr 0x500000e0171ed532
Apr 7 12:49:54 kelsen kernel: [470086.712341] phy-0:3: mptsas: ioc0: delete phy 3, phy-obj (0xffff88007c095c00)
Apr 7 12:49:54 kelsen kernel: [470086.712350] port-0:3: mptsas: ioc0: delete port 3, sas_addr (0x500000e0171ed532)
Apr 7 12:49:54 kelsen kernel: [470086.717117] mptbase: ioc0: LogInfo(0x30030501): Originator={IOP}, Code={Invalid Page}, SubCode(0x0501)
[ligne ci-dessus répétée 11 fois ]
Apr 7 12:49:54 kelsen kernel: [470096.152064] scsi 0:0:3:0: rejecting I/O to offline device
Apr 7 12:49:54 kelsen kernel: [470096.175840] scsi 0:0:3:0: [sdd] Unhandled error code
Apr 7 12:49:54 kelsen kernel: [470096.199312] scsi 0:0:3:0: [sdd] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK
Apr 7 12:49:54 kelsen kernel: [470096.225859] end_request: I/O error, dev sdd, sector 75097451
Apr 7 12:49:54 kelsen kernel: [470096.249935] raid5: Disk failure on sdd3, disabling device.
(idem pour les trois autres partoches).
La machine est en Lenny pure, à l'exception du kernel et du paquet
util-vserver.
Le kernel a été remplacé vendredi par un 2.6.31.12 compilé à la sauce
Debian et patché VServer, tandis que util-vserver est une nouvelle
version rendue nécessaire par le patch.
Lors de l'incident rapporté, la machine affiche l'uptime suivant :
5 days, 12:26:21 | Linux 2.6.31.12-vs2.3.0. Fri Apr 2 02:14:56 2010
tandis qu'elle ne faisait rien de particulier : elle héberge une
dizaine de VServer, mais dont aucun, pas plus qu'elle même, n'était
soumis à une quelconque charge.
Suite à l'incident, /dev/sdd a disparu (ce qui ne me paraît pas
anormal dès l'instant où le contrôleur signale qu'il le vire : udev a
fait son boulot).
J'ai alors rebooté pour voir si sdd était mort ou serait reconnu, et
la machine l'a reconnu (ce qui n'est pas surprenant non plus car
smartd n'a jamais bronché).
J'ai pu alors rajouter chaque partition à son array raid où elles se
sont resynchronisées normalement et, depuis, la machine tourne à
nouveau depuis 2 jours.
Ce que je ne comprends pas dans l'histoire, c'est la raison pour
laquelle un contrôleur scsi décide subitement de virer un disque
(alors qu'on n'est même pas en train de le stresser ; la charge était
négligeable à ce moment) ?
C'est sur ça que d'autres avis me feraient plaisir.
Est-ce qu'il pourrait y avoir un bug dans le driver (d'après le Net,
il y en a eu dans le driver Fusion MPT, mais dans d'anciens noyaux) ?
Si oui, son déclenchement pourrait-il être lié à l'écoulement d'un
certain temps (auquel cas, je babysite la caisse dans 3 jours...) ou
bien est-ce aléatoire (ce qui ne serait pas rassurant non plus) ?
Serait-ce lié au changement de noyau (RAS avec le 2.6.26 de Lenny ou
celui d'Etch avant) ?
Si oui, pourquoi après 5 jours ?
Est-ce un maléfice vaudou lancé par la voisine ? ;-)
Pour l'anecdote, à l'heure où c'est arrivé, je créais un VServer sur
une autre machine, auquel j'ai donné par inadvertance l'IP de la carte
IRMC de ce serveur...
Je cherchais justement pourquoi le réseau ne répondait pas dans le
VServer (et pour cause).
Il est donc raisonnable de penser que l'IRMC s'est ramassé quelques
paquets indésirables dans la figure. Mais de là à ce que ce soit eux
qui aient déclenché l'indigestion du contrôleur scsi, je suppose que
ça devient de la fabulation ?
Bref, je ne la fais pas plus longue, mais je cherche toujours à
comprendre, et les avis que vous auriez seront les bienvenus.
Naturellement, j'ai le log complet sous la main aucazou.
Merci d'avance !
A+
--
JFS.
Reply to: