ltfs MKLTFS - LTFS30210I Cannot open device: failed to open /dev/sg7 (16)

MKLTFS - LTFS30210I Cannot open device: failed to open /dev/sg7 (16)

Open vguilleaume opened this issue 3 years ago • 2 comments

Describe the bug Time to time with a specific installation, when doing a series of LTFS tape format (mkltfs) commands, some mkltfs command reports an issue to open the device.

We retry the command just couple of secondes - minutes after on the same device and the command can be executed.

To Reproduce Execute a series of mkltfs command

Expected behavior

First execution on /dev/sg7 :

{"date_time":"2022/05/06 - 15:07:33:676601 UTC+0000",","id":"48061","mkltfs -f -d /dev/sg7 -n 000062L8 2>&1"}
{"date_time":"2022/05/06 - 15:07:33:738902 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15000I Starting mkltfs, LTFS version 2.4.4.1 (Prelim), log level 2."}
{"date_time":"2022/05/06 - 15:07:33:738959 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15041I Launched by 'mkltfs -f -d /dev/sg7 -n 000062L8'."}
{"date_time":"2022/05/06 - 15:07:33:738976 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15042I This binary is built for Linux (x86_64)."}
{"date_time":"2022/05/06 - 15:07:33:738990 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15043I GCC version is 4.8.5 20150623 (Red Hat 4.8.5-44)."}
{"date_time":"2022/05/06 - 15:07:33:739005 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17087I Kernel version: Linux version 3.10.0-1160.62.1.el7.x86_64 ([email protected]) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-44) (GCC) ) #1 SMP Tue Apr 5 16:57:59 UTC 2022 i386."}
{"date_time":"2022/05/06 - 15:07:33:739156 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17089I Distribution: CentOS Linux release 7.9.2009 (Core)."}
{"date_time":"2022/05/06 - 15:07:33:739181 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17089I Distribution: NAME='CentOS Linux'."}
{"date_time":"2022/05/06 - 15:07:33:739198 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17089I Distribution: CentOS Linux release 7.9.2009 (Core)."}
{"date_time":"2022/05/06 - 15:07:33:739214 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17089I Distribution: CentOS Linux release 7.9.2009 (Core)."}
{"date_time":"2022/05/06 - 15:07:33:739405 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15003I Formatting device '/dev/sg7'."}
{"date_time":"2022/05/06 - 15:07:33:739421 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15004I LTFS volume blocksize: 524288."}
{"date_time":"2022/05/06 - 15:07:33:739444 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15005I Index partition placement policy: None."}
{"date_time":"2022/05/06 - 15:07:33:739458 UTC+0000",","id":"48061","MKLTFS PROCESS : "}
{"date_time":"2022/05/06 - 15:07:33:739473 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11337I Update index-dirty flag (1) - NO_BARCODE (0x0x69a010)."}
{"date_time":"2022/05/06 - 15:07:33:740469 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17085I Plugin: Loading 'sg' tape backend."}
{"date_time":"2022/05/06 - 15:07:33:740550 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30209I Opening a device through sg-ibmtape driver (/dev/sg7)."}
{"date_time":"2022/05/06 - 15:07:33:742526 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30250I Opened the SCSI tape device 15.0.0.0 (/dev/sg7)."}
{"date_time":"2022/05/06 - 15:07:33:742544 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30207I Vendor ID is IBM     ."}
{"date_time":"2022/05/06 - 15:07:33:742558 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30208I Product ID is ULTRIUM-TD9     ."}
{"date_time":"2022/05/06 - 15:07:33:742571 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30214I Firmware revision is N9B0."}
{"date_time":"2022/05/06 - 15:07:33:742586 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30215I Drive serial is C42A857000."}
{"date_time":"2022/05/06 - 15:07:33:742690 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30285I The reserved buffer size of /dev/sg7 is 524288."}
{"date_time":"2022/05/06 - 15:07:33:743503 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30294I Setting up timeout values from RSOC."}
{"date_time":"2022/05/06 - 15:07:33:744659 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30205I TEST_UNIT_READY (0x00) returns -20202."}
{"date_time":"2022/05/06 - 15:07:33:745740 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30205I TEST_UNIT_READY (0x00) returns -20202."}
{"date_time":"2022/05/06 - 15:07:33:746854 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30205I TEST_UNIT_READY (0x00) returns -20202."}
{"date_time":"2022/05/06 - 15:07:33:749615 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17160I Maximum device block size is 1048576."}
{"date_time":"2022/05/06 - 15:07:33:749652 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11330I Loading cartridge."}
{"date_time":"2022/05/06 - 15:07:40:107962 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30205I LOAD_UNLOAD (0x1b) returns -20601."}
{"date_time":"2022/05/06 - 15:07:40:125688 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30252I Logical block protection is disabled."}
{"date_time":"2022/05/06 - 15:07:40:130163 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11332I Load successful."}
{"date_time":"2022/05/06 - 15:07:40:143087 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17157I Changing the drive setting to write-anywhere mode."}
{"date_time":"2022/05/06 - 15:07:40:144076 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15049I Checking the medium (load)."}
{"date_time":"2022/05/06 - 15:07:42:238746 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30252I Logical block protection is disabled."}
{"date_time":"2022/05/06 - 15:07:42:250085 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15010I Creating data partition b on SCSI partition 1."}
{"date_time":"2022/05/06 - 15:07:42:250159 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15011I Creating index partition a on SCSI partition 0."}
{"date_time":"2022/05/06 - 15:07:42:251552 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17165I Resetting the medium's capacity proportion."}
{"date_time":"2022/05/06 - 15:07:47:987453 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11097I Partitioning the medium."}
{"date_time":"2022/05/06 - 15:07:48:001338 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30263I MODESELECT returns Mode Parameters Rounded (-20101) /dev/sg7."}
{"date_time":"2022/05/06 - 15:08:05:880814 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11100I Writing label to partition b."}
{"date_time":"2022/05/06 - 15:08:10:993780 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11278I Writing index to partition b."}
{"date_time":"2022/05/06 - 15:08:10:995052 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30205I READ_ATTR (0x8c) returns -20501."}
{"date_time":"2022/05/06 - 15:08:10:995115 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30263I READ_ATTR returns Invalid Field in CDB (-20501) /dev/sg7."}
{"date_time":"2022/05/06 - 15:08:10:995183 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30233I Cannot read attribute (-20501)."}
{"date_time":"2022/05/06 - 15:08:10:995218 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11336I The attribute does not exist. Ignore the expected error."}
{"date_time":"2022/05/06 - 15:08:10:995251 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17235I Writing index of NO_BARCODE to b (Reason: Format, 0 files) C42A857000."}
{"date_time":"2022/05/06 - 15:08:15:778285 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17236I Wrote index of NO_BARCODE (Gen = 1, Part = b, Pos = 5, C42A857000)."}
{"date_time":"2022/05/06 - 15:08:15:778363 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11337I Update index-dirty flag (0) - NO_BARCODE (0x0x69a010)."}
{"date_time":"2022/05/06 - 15:08:15:778436 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11100I Writing label to partition a."}
{"date_time":"2022/05/06 - 15:08:19:588974 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11278I Writing index to partition a."}
{"date_time":"2022/05/06 - 15:08:19:590905 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30205I READ_ATTR (0x8c) returns -20501."}
{"date_time":"2022/05/06 - 15:08:19:590944 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30263I READ_ATTR returns Invalid Field in CDB (-20501) /dev/sg7."}
{"date_time":"2022/05/06 - 15:08:19:591017 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30233I Cannot read attribute (-20501)."}
{"date_time":"2022/05/06 - 15:08:19:591035 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11336I The attribute does not exist. Ignore the expected error."}
{"date_time":"2022/05/06 - 15:08:22:493581 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17235I Writing index of NO_BARCODE to a (Reason: Format, 0 files) C42A857000."}
{"date_time":"2022/05/06 - 15:08:27:604101 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17236I Wrote index of NO_BARCODE (Gen = 1, Part = a, Pos = 5, C42A857000)."}
{"date_time":"2022/05/06 - 15:08:27:604141 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15013I Volume UUID is: b10b0753-4005-4516-a783-de12fe268cf3."}
{"date_time":"2022/05/06 - 15:08:27:604161 UTC+0000",","id":"48061","MKLTFS PROCESS : "}
{"date_time":"2022/05/06 - 15:08:27:607313 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15019I Volume capacity is 11712 GB."}
{"date_time":"2022/05/06 - 15:08:42:310207 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30252I Logical block protection is disabled."}
{"date_time":"2022/05/06 - 15:08:42:311867 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15024I Medium formatted successfully."}

Next one on /dev/sg5

{"date_time":"2022/05/06 - 15:22:05:776975 UTC+0000",","id":"48066","mkltfs -f -d /dev/sg5 -n 000060L8 2>&1"}
{"date_time":"2022/05/06 - 15:22:05:842243 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS15000I Starting mkltfs, LTFS version 2.4.4.1 (Prelim), log level 2."}
{"date_time":"2022/05/06 - 15:22:05:842348 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS15041I Launched by 'mkltfs -f -d /dev/sg5 -n 000060L8'."}
{"date_time":"2022/05/06 - 15:22:05:842392 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS15042I This binary is built for Linux (x86_64)."}
{"date_time":"2022/05/06 - 15:22:05:842432 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS15043I GCC version is 4.8.5 20150623 (Red Hat 4.8.5-44)."}
{"date_time":"2022/05/06 - 15:22:05:842473 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS17087I Kernel version: Linux version 3.10.0-1160.62.1.el7.x86_64 ([email protected]) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-44) (GCC) ) #1 SMP Tue Apr 5 16:57:59 UTC 2022 i386."}
{"date_time":"2022/05/06 - 15:22:05:842516 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS17089I Distribution: CentOS Linux release 7.9.2009 (Core)."}
{"date_time":"2022/05/06 - 15:22:05:842565 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS17089I Distribution: NAME='CentOS Linux'."}
{"date_time":"2022/05/06 - 15:22:05:842605 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS17089I Distribution: CentOS Linux release 7.9.2009 (Core)."}
{"date_time":"2022/05/06 - 15:22:05:842643 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS17089I Distribution: CentOS Linux release 7.9.2009 (Core)."}
{"date_time":"2022/05/06 - 15:22:05:842684 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS15003I Formatting device '/dev/sg5'."}
{"date_time":"2022/05/06 - 15:22:05:842722 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS15004I LTFS volume blocksize: 524288."}
{"date_time":"2022/05/06 - 15:22:05:842760 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS15005I Index partition placement policy: None."}
{"date_time":"2022/05/06 - 15:22:05:842798 UTC+0000",","id":"48066","MKLTFS PROCESS : "}
{"date_time":"2022/05/06 - 15:22:05:842846 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS11337I Update index-dirty flag (1) - NO_BARCODE (0x0x859010)."}
{"date_time":"2022/05/06 - 15:22:05:843289 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS17085I Plugin: Loading 'sg' tape backend."}
{"date_time":"2022/05/06 - 15:22:05:843349 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30209I Opening a device through sg-ibmtape driver (/dev/sg5)."}
{"date_time":"2022/05/06 - 15:22:05:845280 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30250I Opened the SCSI tape device 18.0.0.0 (/dev/sg5)."}
{"date_time":"2022/05/06 - 15:22:05:845330 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30207I Vendor ID is IBM     ."}
{"date_time":"2022/05/06 - 15:22:05:845369 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30208I Product ID is ULTRIUM-TD9     ."}
{"date_time":"2022/05/06 - 15:22:05:845407 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30214I Firmware revision is N9B0."}
{"date_time":"2022/05/06 - 15:22:05:845446 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30215I Drive serial is C42A857114."}
{"date_time":"2022/05/06 - 15:22:05:845487 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30285I The reserved buffer size of /dev/sg5 is 524288."}
{"date_time":"2022/05/06 - 15:22:05:846407 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30294I Setting up timeout values from RSOC."}
{"date_time":"2022/05/06 - 15:22:05:847631 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30205I TEST_UNIT_READY (0x00) returns -20202."}
{"date_time":"2022/05/06 - 15:22:05:849221 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30205I TEST_UNIT_READY (0x00) returns -20202."}
{"date_time":"2022/05/06 - 15:22:05:850797 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30205I TEST_UNIT_READY (0x00) returns -20202."}
{"date_time":"2022/05/06 - 15:22:05:854377 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS17160I Maximum device block size is 1048576."}
{"date_time":"2022/05/06 - 15:22:05:854423 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS11330I Loading cartridge."}
{"date_time":"2022/05/06 - 15:22:13:547244 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30205I LOAD_UNLOAD (0x1b) returns -20601."}
{"date_time":"2022/05/06 - 15:22:13:554473 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30252I Logical block protection is disabled."}
{"date_time":"2022/05/06 - 15:22:13:563313 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS11332I Load successful."}
{"date_time":"2022/05/06 - 15:22:13:568383 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS17157I Changing the drive setting to write-anywhere mode."}
{"date_time":"2022/05/06 - 15:22:13:569104 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS15049I Checking the medium (load)."}
{"date_time":"2022/05/06 - 15:22:15:736114 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30252I Logical block protection is disabled."}
{"date_time":"2022/05/06 - 15:22:15:747383 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS15010I Creating data partition b on SCSI partition 1."}
{"date_time":"2022/05/06 - 15:22:15:747459 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS15011I Creating index partition a on SCSI partition 0."}
{"date_time":"2022/05/06 - 15:22:15:748968 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS17165I Resetting the medium's capacity proportion."}
{"date_time":"2022/05/06 - 15:22:21:460888 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS11097I Partitioning the medium."}
{"date_time":"2022/05/06 - 15:22:21:475185 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30263I MODESELECT returns Mode Parameters Rounded (-20101) /dev/sg5."}
{"date_time":"2022/05/06 - 15:22:39:449341 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS11100I Writing label to partition b."}
{"date_time":"2022/05/06 - 15:22:44:579117 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS11278I Writing index to partition b."}
{"date_time":"2022/05/06 - 15:22:44:580388 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30205I READ_ATTR (0x8c) returns -20501."}
{"date_time":"2022/05/06 - 15:22:44:580447 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30263I READ_ATTR returns Invalid Field in CDB (-20501) /dev/sg5."}
{"date_time":"2022/05/06 - 15:22:44:580490 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30233I Cannot read attribute (-20501)."}
{"date_time":"2022/05/06 - 15:22:44:580530 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS11336I The attribute does not exist. Ignore the expected error."}
{"date_time":"2022/05/06 - 15:22:44:580569 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS17235I Writing index of NO_BARCODE to b (Reason: Format, 0 files) C42A857114."}
{"date_time":"2022/05/06 - 15:22:49:403626 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS17236I Wrote index of NO_BARCODE (Gen = 1, Part = b, Pos = 5, C42A857114)."}
{"date_time":"2022/05/06 - 15:22:49:403735 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS11337I Update index-dirty flag (0) - NO_BARCODE (0x0x859010)."}
{"date_time":"2022/05/06 - 15:22:49:403781 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS11100I Writing label to partition a."}
{"date_time":"2022/05/06 - 15:22:53:216129 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS11278I Writing index to partition a."}
{"date_time":"2022/05/06 - 15:22:53:217299 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30205I READ_ATTR (0x8c) returns -20501."}
{"date_time":"2022/05/06 - 15:22:53:217358 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30263I READ_ATTR returns Invalid Field in CDB (-20501) /dev/sg5."}
{"date_time":"2022/05/06 - 15:22:53:217401 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30233I Cannot read attribute (-20501)."}
{"date_time":"2022/05/06 - 15:22:53:217440 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS11336I The attribute does not exist. Ignore the expected error."}
{"date_time":"2022/05/06 - 15:22:56:177904 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS17235I Writing index of NO_BARCODE to a (Reason: Format, 0 files) C42A857114."}
{"date_time":"2022/05/06 - 15:23:01:302045 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS17236I Wrote index of NO_BARCODE (Gen = 1, Part = a, Pos = 5, C42A857114)."}
{"date_time":"2022/05/06 - 15:23:01:302156 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS15013I Volume UUID is: 796fc7d9-8403-4e20-847d-5bd2938c48ad."}
{"date_time":"2022/05/06 - 15:23:01:302203 UTC+0000",","id":"48066","MKLTFS PROCESS : "}
{"date_time":"2022/05/06 - 15:23:01:305198 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS15019I Volume capacity is 11712 GB."}
{"date_time":"2022/05/06 - 15:23:15:976248 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS30252I Logical block protection is disabled."}
{"date_time":"2022/05/06 - 15:23:15:977984 UTC+0000",","id":"48066","MKLTFS PROCESS : LTFS15024I Medium formatted successfully."}

And then again on /dev/sg7 which now fails with the error messages related to 'open device'.

{"date_time":"2022/05/06 - 15:28:06:511289 UTC+0000",","id":"48061","mkltfs -f -d /dev/sg7 -n 000066L8 2>&1"}
{"date_time":"2022/05/06 - 15:28:06:569593 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15000I Starting mkltfs, LTFS version 2.4.4.1 (Prelim), log level 2."}
{"date_time":"2022/05/06 - 15:28:06:569696 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15041I Launched by 'mkltfs -f -d /dev/sg7 -n 000066L8'."}
{"date_time":"2022/05/06 - 15:28:06:569745 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15042I This binary is built for Linux (x86_64)."}
{"date_time":"2022/05/06 - 15:28:06:569787 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15043I GCC version is 4.8.5 20150623 (Red Hat 4.8.5-44)."}
{"date_time":"2022/05/06 - 15:28:06:569828 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17087I Kernel version: Linux version 3.10.0-1160.62.1.el7.x86_64 ([email protected]) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-44) (GCC) ) #1 SMP Tue Apr 5 16:57:59 UTC 2022 i386."}
{"date_time":"2022/05/06 - 15:28:06:569894 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17089I Distribution: CentOS Linux release 7.9.2009 (Core)."}
{"date_time":"2022/05/06 - 15:28:06:569935 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17089I Distribution: NAME='CentOS Linux'."}
{"date_time":"2022/05/06 - 15:28:06:569975 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17089I Distribution: CentOS Linux release 7.9.2009 (Core)."}
{"date_time":"2022/05/06 - 15:28:06:570015 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17089I Distribution: CentOS Linux release 7.9.2009 (Core)."}
{"date_time":"2022/05/06 - 15:28:06:570056 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15003I Formatting device '/dev/sg7'."}
{"date_time":"2022/05/06 - 15:28:06:570109 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15004I LTFS volume blocksize: 524288."}
{"date_time":"2022/05/06 - 15:28:06:570146 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15005I Index partition placement policy: None."}
{"date_time":"2022/05/06 - 15:28:06:570181 UTC+0000",","id":"48061","MKLTFS PROCESS : "}
{"date_time":"2022/05/06 - 15:28:06:570226 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11337I Update index-dirty flag (1) - NO_BARCODE (0x0x1771010)."}
{"date_time":"2022/05/06 - 15:28:06:570622 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17085I Plugin: Loading 'sg' tape backend."}
{"date_time":"2022/05/06 - 15:28:06:570679 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30209I Opening a device through sg-ibmtape driver (/dev/sg7)."}
{"date_time":"2022/05/06 - 15:28:06:571386 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30210I Cannot open device: failed to open /dev/sg7 (16)."}
{"date_time":"2022/05/06 - 15:28:06:571613 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS12012E Cannot open device: failed backend open call."}
{"date_time":"2022/05/06 - 15:28:06:571656 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15009E Cannot open device '/dev/sg7' (-21711)."}
{"date_time":"2022/05/06 - 15:28:06:571696 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15023I Formatting failed."}

And restart again 4 seconds later :

{"date_time":"2022/05/06 - 15:28:10:661453 UTC+0000",","id":"48061","mkltfs -f -d /dev/sg7 -n 000066L8 2>&1"}
{"date_time":"2022/05/06 - 15:28:10:707829 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15000I Starting mkltfs, LTFS version 2.4.4.1 (Prelim), log level 2."}
{"date_time":"2022/05/06 - 15:28:10:707906 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15041I Launched by 'mkltfs -f -d /dev/sg7 -n 000066L8'."}
{"date_time":"2022/05/06 - 15:28:10:707971 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15042I This binary is built for Linux (x86_64)."}
{"date_time":"2022/05/06 - 15:28:10:708033 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15043I GCC version is 4.8.5 20150623 (Red Hat 4.8.5-44)."}
{"date_time":"2022/05/06 - 15:28:10:708071 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17087I Kernel version: Linux version 3.10.0-1160.62.1.el7.x86_64 ([email protected]) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-44) (GCC) ) #1 SMP Tue Apr 5 16:57:59 UTC 2022 i386."}
{"date_time":"2022/05/06 - 15:28:10:708107 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17089I Distribution: CentOS Linux release 7.9.2009 (Core)."}
{"date_time":"2022/05/06 - 15:28:10:708147 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17089I Distribution: NAME='CentOS Linux'."}
{"date_time":"2022/05/06 - 15:28:10:708183 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17089I Distribution: CentOS Linux release 7.9.2009 (Core)."}
{"date_time":"2022/05/06 - 15:28:10:708215 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17089I Distribution: CentOS Linux release 7.9.2009 (Core)."}
{"date_time":"2022/05/06 - 15:28:10:708251 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15003I Formatting device '/dev/sg7'."}
{"date_time":"2022/05/06 - 15:28:10:708283 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15004I LTFS volume blocksize: 524288."}
{"date_time":"2022/05/06 - 15:28:10:708319 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15005I Index partition placement policy: None."}
{"date_time":"2022/05/06 - 15:28:10:708359 UTC+0000",","id":"48061","MKLTFS PROCESS : "}
{"date_time":"2022/05/06 - 15:28:10:708425 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11337I Update index-dirty flag (1) - NO_BARCODE (0x0xaf1010)."}
{"date_time":"2022/05/06 - 15:28:10:708509 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17085I Plugin: Loading 'sg' tape backend."}
{"date_time":"2022/05/06 - 15:28:10:708548 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30209I Opening a device through sg-ibmtape driver (/dev/sg7)."}
{"date_time":"2022/05/06 - 15:28:10:710147 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30250I Opened the SCSI tape device 15.0.0.0 (/dev/sg7)."}
{"date_time":"2022/05/06 - 15:28:10:710196 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30207I Vendor ID is IBM     ."}
{"date_time":"2022/05/06 - 15:28:10:710271 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30208I Product ID is ULTRIUM-TD9     ."}
{"date_time":"2022/05/06 - 15:28:10:710308 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30214I Firmware revision is N9B0."}
{"date_time":"2022/05/06 - 15:28:10:710370 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30215I Drive serial is C42A857000."}
{"date_time":"2022/05/06 - 15:28:10:710427 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30285I The reserved buffer size of /dev/sg7 is 524288."}
{"date_time":"2022/05/06 - 15:28:10:711110 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30294I Setting up timeout values from RSOC."}
{"date_time":"2022/05/06 - 15:28:10:712213 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30205I TEST_UNIT_READY (0x00) returns -20202."}
{"date_time":"2022/05/06 - 15:28:10:713315 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30205I TEST_UNIT_READY (0x00) returns -20202."}
{"date_time":"2022/05/06 - 15:28:10:714414 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30205I TEST_UNIT_READY (0x00) returns -20202."}
{"date_time":"2022/05/06 - 15:28:10:717191 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17160I Maximum device block size is 1048576."}
{"date_time":"2022/05/06 - 15:28:10:717251 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11330I Loading cartridge."}
{"date_time":"2022/05/06 - 15:28:12:622535 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30205I LOAD_UNLOAD (0x1b) returns -20601."}
{"date_time":"2022/05/06 - 15:28:12:629705 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30252I Logical block protection is disabled."}
{"date_time":"2022/05/06 - 15:28:12:638543 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11332I Load successful."}
{"date_time":"2022/05/06 - 15:28:12:643546 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17157I Changing the drive setting to write-anywhere mode."}
{"date_time":"2022/05/06 - 15:28:12:644251 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15049I Checking the medium (load)."}
{"date_time":"2022/05/06 - 15:28:14:804943 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30252I Logical block protection is disabled."}
{"date_time":"2022/05/06 - 15:28:14:817038 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15010I Creating data partition b on SCSI partition 1."}
{"date_time":"2022/05/06 - 15:28:14:817075 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15011I Creating index partition a on SCSI partition 0."}
{"date_time":"2022/05/06 - 15:28:14:818482 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17165I Resetting the medium's capacity proportion."}
{"date_time":"2022/05/06 - 15:28:20:526086 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11097I Partitioning the medium."}
{"date_time":"2022/05/06 - 15:28:20:540829 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30263I MODESELECT returns Mode Parameters Rounded (-20101) /dev/sg7."}
{"date_time":"2022/05/06 - 15:28:38:425014 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11100I Writing label to partition b."}
{"date_time":"2022/05/06 - 15:28:43:513927 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11278I Writing index to partition b."}
{"date_time":"2022/05/06 - 15:28:43:515118 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30205I READ_ATTR (0x8c) returns -20501."}
{"date_time":"2022/05/06 - 15:28:43:515177 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30263I READ_ATTR returns Invalid Field in CDB (-20501) /dev/sg7."}
{"date_time":"2022/05/06 - 15:28:43:515219 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30233I Cannot read attribute (-20501)."}
{"date_time":"2022/05/06 - 15:28:43:515259 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11336I The attribute does not exist. Ignore the expected error."}
{"date_time":"2022/05/06 - 15:28:43:515299 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17235I Writing index of NO_BARCODE to b (Reason: Format, 0 files) C42A857000."}
{"date_time":"2022/05/06 - 15:28:48:298222 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17236I Wrote index of NO_BARCODE (Gen = 1, Part = b, Pos = 5, C42A857000)."}
{"date_time":"2022/05/06 - 15:28:48:298332 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11337I Update index-dirty flag (0) - NO_BARCODE (0x0xaf1010)."}
{"date_time":"2022/05/06 - 15:28:48:298377 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11100I Writing label to partition a."}
{"date_time":"2022/05/06 - 15:28:52:167298 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11278I Writing index to partition a."}
{"date_time":"2022/05/06 - 15:28:52:168474 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30205I READ_ATTR (0x8c) returns -20501."}
{"date_time":"2022/05/06 - 15:28:52:168531 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30263I READ_ATTR returns Invalid Field in CDB (-20501) /dev/sg7."}
{"date_time":"2022/05/06 - 15:28:52:168572 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30233I Cannot read attribute (-20501)."}
{"date_time":"2022/05/06 - 15:28:52:168612 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS11336I The attribute does not exist. Ignore the expected error."}
{"date_time":"2022/05/06 - 15:28:55:075571 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17235I Writing index of NO_BARCODE to a (Reason: Format, 0 files) C42A857000."}
{"date_time":"2022/05/06 - 15:29:00:195928 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS17236I Wrote index of NO_BARCODE (Gen = 1, Part = a, Pos = 5, C42A857000)."}
{"date_time":"2022/05/06 - 15:29:00:196031 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15013I Volume UUID is: dbea8233-a631-45d9-aaa4-839870c4b34c."}
{"date_time":"2022/05/06 - 15:29:00:196074 UTC+0000",","id":"48061","MKLTFS PROCESS : "}
{"date_time":"2022/05/06 - 15:29:00:199069 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15019I Volume capacity is 11712 GB."}
{"date_time":"2022/05/06 - 15:29:14:903492 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30252I Logical block protection is disabled."}
{"date_time":"2022/05/06 - 15:29:14:905202 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS15024I Medium formatted successfully."}

Environment:

OS: CentOS 7.9 - 2009
LTFS Version - Stable LTFS version 2.4.4.1
Drive - IBM / Quantum LTO9
Tape Library - Quantum i6

May 09 '22 12:05 vguilleaume

{"date_time":"2022/05/06 - 15:28:06:570679 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30209I Opening a device through sg-ibmtape driver (/dev/sg7)."}
{"date_time":"2022/05/06 - 15:28:06:571386 UTC+0000",","id":"48061","MKLTFS PROCESS : LTFS30210I Cannot open device: failed to open /dev/sg7 (16)."}

The log says open() call is failed by EBUSY. I believe this is not a bug of LTFS. It simply open the device and use it if it is successfully done. And close the device when it is finished.

#define	EBUSY		16	/* Device or resource busy */

My first impression is /dev/sg7 was used by someone at failure. If not, you need to investigate the kernel log first. And you might need to contact to the CentOS if required.

May 09 '22 23:05 piste-jp

thanks @piste-jp-ibm for your quick answer ; The strange thing is that we notice a delay of around 15 minutes between two mkltfs command execution on this /dev/sg7 device.

Perhaps there is something else that can block this device , i will investigate this way and update you about my finding.

May 10 '22 07:05 vguilleaume

Close this because there is no response for a long time.

Oct 17 '22 01:10 piste-jp

ltfs ltfs copied to clipboard

MKLTFS - LTFS30210I Cannot open device: failed to open /dev/sg7 (16)

ltfs
ltfs copied to clipboard