LTO 9 Timeout beim Labeln

[Thoxel]

Hallo,

LTO9 SAS MSL2024 HPE Libary
PBS: 3.1-2
Kernel 6.5
Firmware Tape: Q3F9 (neuste)
DL360 GEN10 BIOS und HBA (kompatibel) auch auf dem neusten Stand

Nachdem das Tape durch die Libary initialisiert wurde (seit LTO 8 notwendig), ist nun das Label durch des PBS notwendig. Beim Labeln oder Formatieren des LTO9-Tapes, dauert es wohl zu lange (meine Vermutung), folglich läuft der Label/Formatier-Job in den Timeout. Daraus ist dann das Device "Offline" im PBS (siehe Fehlermeldung unten) und der PBS muss neu gestartet werden. Hierbei sieht man in der Managementoberfläche der Libary, dass der Job weiterläuft und nach ca. 35-40 Minuten abgeschlossen ist (Der Label Job bricht nach bereits 20 Minuten im PBS ab). Nach dem Neustart des PBS und neuem Klick auf Label Media, geht es dann in unter 2-5 Sekunden durch. Des Weiteren läuft das Sichern selbst dann nach diesem "Workaround" durch.

Frage daraus dann, liegt es am TImeout oder ist es ein anderes Problem? Wenn ja, wie kann man den Timeout hochsetzten?

FYI, das gleiche Problem war auch schon vor der Version 3.1-2 da. Bei LTO7 war dies nicht, da ging das alles super schnell.

2023-12-01T16:19:58+01:00: TASK ERROR: open drive 'LTO9-MSL-Links' (/dev/tape/by-id/scsi-JPG34XXXX-XX) failed - SCSI inquiry failed - do_scsi_pt failed with err ENXIO: No such device or address
2023-12-01T14:58:22+01:00: TASK ERROR: scsi command failed: transport error


[ 27.966300] Loading iSCSI transport class v2.0-870.
[ 143.760131] systemd[2137]: memfd_create() called without MFD_EXEC or MFD_NOEXEC_SEAL set
[ 1185.270101] smartpqi 0000:11:00.0: resetting scsi 15:0:0:0 due to cmd 0x04
[ 1196.273901] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 10 seconds for 1 outstanding command(s)
[ 1206.277802] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 20 seconds for 1 outstanding command(s)
[ 1216.281709] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 30 seconds for 1 outstanding command(s)
[ 1226.285594] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 40 seconds for 1 outstanding command(s)
[ 1236.289499] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 50 seconds for 1 outstanding command(s)
[ 1246.293387] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 60 seconds for 1 outstanding command(s)
[ 1256.297283] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 70 seconds for 1 outstanding command(s)
[ 1266.301184] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 80 seconds for 1 outstanding command(s)
[ 1276.305082] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 90 seconds for 1 outstanding command(s)
[ 1286.308983] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 100 seconds for 1 outstanding command(s)
[ 1296.312873] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 110 seconds for 1 outstanding command(s)
[ 1306.316787] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 120 seconds for 1 outstanding command(s)
[ 1316.320668] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 130 seconds for 1 outstanding command(s)
[ 1326.324570] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 140 seconds for 1 outstanding command(s)
[ 1336.328461] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 150 seconds for 1 outstanding command(s)
[ 1346.332353] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 160 seconds for 1 outstanding command(s)
[ 1356.336264] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 170 seconds for 1 outstanding command(s)
[ 1366.340158] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 180 seconds for 1 outstanding command(s)
[ 1376.344053] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 190 seconds for 1 outstanding command(s)
[ 1386.347952] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 200 seconds for 1 outstanding command(s)
[ 1396.351846] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 210 seconds for 1 outstanding command(s)
[ 1406.355740] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 220 seconds for 1 outstanding command(s)
[ 1416.359649] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 230 seconds for 1 outstanding command(s)
[ 1426.363538] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 240 seconds for 1 outstanding command(s)
[ 1436.367356] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 250 seconds for 1 outstanding command(s)
[ 1446.371339] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 260 seconds for 1 outstanding command(s)
[ 1456.375227] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 270 seconds for 1 outstanding command(s)
[ 1466.379129] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 280 seconds for 1 outstanding command(s)
[ 1476.383021] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 290 seconds for 1 outstanding command(s)
[ 1486.386924] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 300 seconds for 1 outstanding command(s)
[ 1496.390817] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 310 seconds for 1 outstanding command(s)
[ 1506.394721] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 320 seconds for 1 outstanding command(s)
[ 1516.398612] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 330 seconds for 1 outstanding command(s)
[ 1526.402515] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 340 seconds for 1 outstanding command(s)
[ 1536.406407] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 350 seconds for 1 outstanding command(s)
[ 1546.410311] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 360 seconds for 1 outstanding command(s)
[ 1556.414199] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 370 seconds for 1 outstanding command(s)
[ 1566.418098] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 380 seconds for 1 outstanding command(s)
[ 1576.422010] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 390 seconds for 1 outstanding command(s)
[ 1586.425894] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 400 seconds for 1 outstanding command(s)
[ 1596.429798] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 410 seconds for 1 outstanding command(s)
[ 1606.433683] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 420 seconds for 1 outstanding command(s)
[ 1616.437589] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 430 seconds for 1 outstanding command(s)
[ 1626.441482] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 440 seconds for 1 outstanding command(s)
[ 1636.445373] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 450 seconds for 1 outstanding command(s)
[ 1646.449260] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 460 seconds for 1 outstanding command(s)
[ 1656.453178] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 470 seconds for 1 outstanding command(s)
[ 1666.457094] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 480 seconds for 1 outstanding command(s)
[ 1676.460952] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 490 seconds for 1 outstanding command(s)
[ 1686.464874] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 500 seconds for 1 outstanding command(s)
[ 1696.468756] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 510 seconds for 1 outstanding command(s)
[ 1706.472652] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 520 seconds for 1 outstanding command(s)
[ 1716.476551] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 530 seconds for 1 outstanding command(s)
[ 1726.480446] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 540 seconds for 1 outstanding command(s)
[ 1736.484336] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 550 seconds for 1 outstanding command(s)
[ 1746.488245] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 560 seconds for 1 outstanding command(s)
[ 1756.492153] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 570 seconds for 1 outstanding command(s)
[ 1766.496039] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 580 seconds for 1 outstanding command(s)
[ 1776.499942] smartpqi 0000:11:00.0: scsi 15:0:0:0: waiting 590 seconds for 1 outstanding command(s)
[ 1786.263843] smartpqi 0000:11:00.0: scsi 15:0:0:0: timed out after 600 seconds waiting for 1 outstanding command(s)
[ 1786.264218] smartpqi 0000:11:00.0: reset of scsi 15:0:0:0: FAILED
[ 1786.264566] st 15:0:0:0: Device offlined - not ready after error recovery


Best Regards

 

[dcsapak]

der log sieht für mich so aus als würde der HBA/Controller versuchen das drive zu resetten:

[ 1185.270101] smartpqi 0000:11:00.0: resetting scsi 15:0:0:0 due to cmd 0x04

und davon erholt es sich nicht mehr?

labeln im PBS sollte wirklich nicht so lang dauern, ist ein spulen am anfang und schreiben von ein paar blöcken. Gibts vom changer/drive auch ein log? steht da vielleicht mehr drin?

 

[Thoxel]

Logs nicht wirklich, währenddessen ist das Laufwerk aber im Status "Calibrating" (dauert 30-40m) und erst wenn das abgeschlossen ist, regiert das Laufwerk wieder nach dem Reboot des PBS. Beim zweiten Labeln ist der Status erst "Rewinding" und dann "Writing" (dauert wenige Sekunden) und dann ist es erfolgreich.

Schneidet sich die Grundkalibrierung (New Media Initialization) des Tapes durch die Libary (seit LTO 8 notwendig) mit der Formatierung, die der PBS braucht, sodass es beim Labeln (bzw. grundsätzlich verwendet werden kann) noch mal komplett neu kalibriert werden muss?

 

[dcsapak]

Schneidet sich die Grundkalibrierung (New Media Initialization) des Tapes durch die Libary (seit LTO 8 notwendig) mit der Formatierung, die der PBS braucht, sodass es beim Labeln (bzw. grundsätzlich verwendet werden kann) noch mal komplett neu kalibriert werden muss?

scheinbar. ich würde das mal für alle tapes durchlaufen lassen, und erst danach anfangen im pbs zu labeln

 

[Thoxel]

Das ist ja bereits für alle Tapes passiert (meinte ich mit Grundkalibrierung). Daher ist mein Gedanke, dass die Grundkalibrierung (Initialisierung) mit dem Format des PBS interferiert.

Kann hierfür "tiefere" Debugs mitlaufen lassen, oder ist das, was der Kernel im Dmesg anzeigt alles was wir bekommen? Kann natürlich nur eine Korrelation sein und keine Kausalität.


"Media initialization has been implemented in LTO-9 technology to optimize data placement according to the characteristics of each LTO-9
cartridge.
Each new LTO-9 cartridge requires this one-time initialization prior to starting read/write operations, this is only required for the first use of
a new LTO-9 cartridge, subsequent loads do not require additional initialization"
https://www.hpe.com/psnow/doc/a50005444enw

 

[dcsapak]

Das ist ja bereits für alle Tapes passiert (meinte ich mit Grundkalibrierung). Daher ist mein Gedanke, dass die Grundkalibrierung (Initialisierung) mit dem Format des PBS interferiert.

Kann hierfür "tiefere" Debugs mitlaufen lassen, oder ist das, was der Kernel im Dmesg anzeigt alles was wir bekommen? Kann natürlich nur eine Korrelation sein und keine Kausalität.


"Media initialization has been implemented in LTO-9 technology to optimize data placement according to the characteristics of each LTO-9
cartridge.
Each new LTO-9 cartridge requires this one-time initialization prior to starting read/write operations, this is only required for the first use of
a new LTO-9 cartridge, subsequent loads do not require additional initialization"
https://www.hpe.com/psnow/doc/a50005444enw

ok soweit ich das verstehe, sollte das nichts daran ändern wie man drauf schreibt oder liest, solange man die tapes vorher initialisiert

die frage ist warum er die tapes (nochmal?) initialisieren will beim labeln, und warum nur beim 1. mal? klingt sehr seltsam

leider ist die info vom dmesg alles was wir vom kernel da kriegen wahrscheinlich, aber die library hat vielleicht noch mehr logs?