Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add simh image file support to tape device #100

Closed
uweseimet opened this issue Nov 11, 2024 · 137 comments
Closed

Add simh image file support to tape device #100

uweseimet opened this issue Nov 11, 2024 · 137 comments
Assignees
Labels
enhancement New feature or request help wanted Extra attention is needed

Comments

@uweseimet
Copy link
Owner

uweseimet commented Nov 11, 2024

This is a follow-up ticket to #93. The tape device (SCPT) support in SCSI2Pi 4.0 focuses on reading and writing tar files. This has been tested with tar (Linux) and with Gemar (Atari).

In order to support more sophisticated tape drivers, which for instance make use of filemarks and of (reverse) spacing, a different image file format is required. tar files only contain the actual archived data, but not any other objects like filemarks or end-of-data markers, which are used by some drivers, e.g. bacula.

In the ideal case SCSI2Pi can use the same format that is used by open-simh, see https://github.com/open-simh/simh. See http://simh.trailing-edge.com/docs/simh_magtape.pdf for the specification of this file format.

@uweseimet uweseimet added enhancement New feature or request help wanted Extra attention is needed labels Nov 11, 2024
@uweseimet uweseimet self-assigned this Nov 11, 2024
@uweseimet uweseimet pinned this issue Nov 11, 2024
@uweseimet uweseimet moved this to In progress in SCSI2Pi release 4.1 Nov 11, 2024
@uweseimet
Copy link
Owner Author

uweseimet commented Nov 11, 2024

@Pacjunk The issue_100 branch now contains initial code that for .tap files supports the simh file format. I have already tested this code with my limited setup. tar can successfully write/read to/from .tap files in the new format. This means that at least consecutive data blocks are dealt with correctly, just like before with the proprietary raw format.
I downloaded http://www.bitsavers.org/bits/DEC/vax/vms/TK50/aq-mi45a-be_vms_v4_v5_mand_upd_1988.tap in order to see what happens when I use this image file together with tar. Of course this cannot work, but it reveals that at least the size of the first object (a label I guess) is correctly evaluated:

[2024-11-11 22:28:12.431] [debug] (ID 3) - Controller is executing READ(6)/GET MESSAGE(6), CDB 08:01:00:00:14:00
[2024-11-11 22:28:12.431] [debug] (ID:LUN 3:0) - Device is executing READ(6)/GET MESSAGE(6) ($08)
[2024-11-11 22:28:12.431] [trace] (ID:LUN 3:0) - Position: 0, byte count: 10240
[2024-11-11 22:28:12.431] [trace] (ID:LUN 3:0) - Read simh header with class number 0, marker value/record length 80
[2024-11-11 22:28:12.431] [trace] (ID:LUN 3:0) - Searching for object type 0, found type 0 at position 0
[2024-11-11 22:28:12.431] [trace] (ID:LUN 3:0) - Actual block length of 80 byte(s) does not match expected block length of 512 byte(s)
[2024-11-11 22:28:12.432] [debug] (ID 3) - MEDIUM ERROR (Sense Key $03), NO ADDITIONAL_SENSE INFORMATION (ASC $00), ASCQ $00

When you start testing (e.g. by labelling a blank "tape") I expect some issues, new ones or familiar ones, we will see ...

@Pacjunk
Copy link

Pacjunk commented Nov 11, 2024

Wow, you have been busy overnight! I'll see if I can make some time...

@Pacjunk
Copy link

Pacjunk commented Nov 12, 2024

OK, I rebuilt on the issue_100 branch and did some more testing (sorry still haven't connected that tape drive yet)...

I initialised (labelled) a tape (success)
init.txt

then I mounted that tape using the label (success)
mount.txt

then I did a "dir" on the blank tape (success)
dir empty.txt

then I attempted to copy a file to the tape (failed parity errors, device errors)
copy file.txt

Another "dir" on the tape (more parity errors etc)
dir after copy.txt

I then connected a pre-existing simh image from bitsavers. I mounted the tape (success!)
mount simh.txt

Then a "dir" on the tape to check contents (parity errors, but did display the first file name on the tape - not all)
dir simh.txt

That is all I had time for tonight. I'll try to get to the physical tape drive soon...

@uweseimet
Copy link
Owner Author

uweseimet commented Nov 12, 2024

@Pacjunk I'm afraid I don't know what a parity error in this context means. The tape code does not deal with parity. My guess is that your driver is not satisfied with the data it sees or there are (still) issues with the tape-related data returned by REQUEST SENSE. But the data returned appear to be better than before now, because on first sight I could not find any attempt to reverse-space anymore in the logs.

I just fixed some issues and improved the logging, please use the latest avallable issue_100 branch for your next test. There is now also initial reverse-spacing support. Reminder: Always add information on the commit ID you were testing.

Please also do not forget to verify your web UI issue (see my comment in the issue_93 ticket about the web UI).

Regarding init.txt there is no command writing the label. Line 105 appears to successfully read it, so it must have been created before. Please ensure that no write operations are missing in the logs.
It may make sense, though, to focus on existing simh files first, e.g. your "dir" test. As long as reading data does not fully work, writing data is unlikely to work better.

I noticed that the existing simh files contain private data records, which SCSI2Pi will not be able to process. See the simh file specification for details on private records.

[2024-11-12 19:42:12.985] [trace] (ID:LUN 3:0) - Read simh header with class 5, marker value/record length $0544353 from position 0

This is not necessarily an issue, but it means that there are custom data in the simh files that only the software that created these files can make use of. Or the detection of this type is still a bug in SCSI2Pi.

And one more thing: As far as I can tell you are testing with an optimized build. If this is the case, please test with a debug build, so that assertions are enabled.

@Pacjunk
Copy link

Pacjunk commented Nov 13, 2024

Looks like my previous logs were truncated...

I ran some more test with build 99272d6.

Initialise a tape: init2.txt
Initialise a tape with erase: init erase.txt
Mount (any label) : mount specified.txt
Mount (specified label) : mount specified.txt
Copy File (still fails) : copy file.txt

According to the help, "parity error" could mean almost anything...

 		If this message is associated with a status code returned
                by a request to a magnetic tape driver, one or more of the
                following conditions can cause this error:

                  Attempt to read beyond the logical end of volume
                  Control bus parity error
                  Correctable data error (PE only)
                  Correctable skew (PE only)
                  CRC error (NRZI only)
                  Data bus parity error
                  Format error (PE only)
                  Invalid tape mark (NRZI only)
                  Longitudinal parity error (NRZI only)
                  Map parity error
                  MASSBUS control parity error
                  MASSBUS data parity error
                  Nonstandard gap
                  Read data substitute
                  Uncorrectable error (PE only)
                  Vertical parity error (NRZI only)


How do I do a debug build? I just do "make s2p". I assume there is some switch?

@uweseimet
Copy link
Owner Author

uweseimet commented Nov 14, 2024

@Pacjunk Please refer to https://github.com/uweseimet/scsi2pi/wiki/Compilation-Instructions for build instructions.
99272d6 is rather old, 25 hours according to git. Please always use the latest available issue_100 branch for new tests. Otherwise you are spending time on outdated code. Please also read my latest comments before starting to test.
My recommendation is not to test any write operations for now, but to focus on existing simh files, which you have checked with the new s2psimh tool, please see my previous comments for details, also in #101.

@Pacjunk
Copy link

Pacjunk commented Nov 14, 2024

I'm sorry, but given that it takes 3-4 hours to do a build, I'm not constantly checking for updates. I tend to do a rebuild at night and then maybe test the next day. Because of time zone differences, this is when you make your changes so I'm always testing stale code. I will try the debug build. Also you edit your comments and github doesn't send an email for edits, only the original.

I managed to get a couple of tape drives working (had to reinstall in another enclosure), then one drive decided to chew some tapes, so this required dismantling to get the tapes out...

Anyway, these are the logs: (I tested first without a tape loaded, then with a tape loaded)

Sony SDT-5000 :
sdt5000.txt

DEC TZ87 in TK50/70 compatibility mode (read only):
tz87.txt

DEC TZ87 with TK85 tape:
tz87_CT3.txt

I had some problems with that last drive. Not able to initialise tapes for some reason, but seems to read the tape and make all the right noises.

@Pacjunk
Copy link

Pacjunk commented Nov 14, 2024

OK, I rebuilt with debug to version 4e1f05a, and tested with the prebuilt simh image.

Mounting the tape (successfull):
mount.txt

Directory listing of tape (failed):
dir.txt

Interestingly, this time I didn't get the generic parity error. The OS reported "file or directory lookup failed. magnetic tape position lost"

Is there some sort of utility/option that can "sniff" the traffic going to and from the real drive. Might be interesting to compare it to the emulated drive.

@Pacjunk
Copy link

Pacjunk commented Nov 14, 2024

Here is the dump of the file I'm using. It appears to not be in ANSI format. There are 4 files on the tape. VMS054.A, .B, .C, .D. Only the first filename (VMS054.A) is displayed before the error. The filenames are stored next to the data, so you need to wind through the tape to find them.
simh dump.txt

@uweseimet
Copy link
Owner Author

uweseimet commented Nov 14, 2024

@Pacjunk I have had a quick look at the latest s2p logs, thank you. I don't think the mount log is required anymore, unless something changes for the worse and mounting fails. In dir.txt I stumble on this:

[2024-11-14 16:47:57.536] [debug] (ID 3) - Controller is executing SPACE(6), CDB 11:00:00:7f:ff:00
[2024-11-14 16:47:57.537] [debug] (ID:LUN 3:0) - Device is executing SPACE(6) ($11)
[2024-11-14 16:47:57.538] [trace] (ID:LUN 3:0) - Read SIMH header with class 0, value $0002000 at position 268
[2024-11-14 16:47:57.538] [trace] (ID:LUN 3:0) - Searching for object type 0, found type 0 at position 268
[2024-11-14 16:47:57.539] [trace] (ID:LUN 3:0) - Read SIMH header with class 0, value $4000100 at position 272
[2024-11-14 16:47:57.539] [trace] (ID:LUN 3:0) - Searching for object type 0, found type 0 at position 272
[2024-11-14 16:47:57.540] [trace] (ID:LUN 3:0) - Read SIMH header with class 0, value $0010001 at position 276
[2024-11-14 16:47:57.540] [trace] (ID:LUN 3:0) - Searching for object type 0, found type 0 at position 276
[2024-11-14 16:47:57.542] [trace] (ID:LUN 3:0) - Read SIMH header with class 0, value $0000001 at position 280
[2024-11-14 16:47:57.544] [trace] (ID:LUN 3:0) - Searching for object type 0, found type 0 at position 280
[2024-11-14 16:47:57.544] [trace] (ID:LUN 3:0) - Read SIMH header with class 0, value $0000000 at position 284
[2024-11-14 16:47:57.545] [trace] (ID:LUN 3:0) - Searching for object type 0, found type 1 at position 284
[2024-11-14 16:47:57.545] [trace] (ID:LUN 3:0) - Encountered filemark while spacing over blocks

s2p finds the data record at offset 268, which according to the s2psimh dump makes sense. But then it finds a data record also at offset 272, which is wrong. From the dump we can see that the next data record is at offfset 8468. s2p does not appear to skip the data record correctly and is out-of-sync. I will have a look at this.
Maybe you can also compare the dump with the s2p log, because four eyes see more than two.

Instead of the s2psimh dump of your file, can you please provide me a download link for the simh file you are using? I can then create a dump myself, and also have the file available for testing.
You say there are 4 files on this tape. Do the filenames appear in the dump? There are 3 short data blocks with what appears to be names in them at the start and 2 at the end. In between there are only regular data blocks of 8192 bytes. Is this the content you would expect? In case you know the names of the files on the tape and they are not included in these short blocks, are they included in the 8192 byte blocks? You can grep for them, e.g. with

s2psimh -d YOUR_TAP_FILE | grep NAME_OF_THE_FILE

If we assume that the filenames are visibile in the ASCII data of the dump, they should be found.

The traffic between your driver and the emulated drive is fully covered by logging on trace level. A tool would not provide more information.
It would be nice, though, if there was a tool for your workstation that shows the traffic between your workstation and a real drive. For the Atari there is such a tool, maybe also for your workstation?

Thank you for running the s2pexec commands. The Sony and the DEC drive appear to support reverse-spacing. Since my drive also supports it, this feature appears to be quite common. But that's fine for SCSI2Pi, because I added reverse-spacing about 2 days ago to the issue_100 branch.

Regarding the issue_100 branch it's best if you update and re-compile (s2p and s2psimh are sufficient) before running new tests. Re-compiling will not always take very long, because usually only a few files may have changed since the last build.

Any news on your web UI issue?

@uweseimet
Copy link
Owner Author

uweseimet commented Nov 14, 2024

@Pacjunk I have identified why s2p was out-of-sync. Please update and re-build issue_100 and run the directory test again. The s2p log should reveal the change, i.e. s2p should now skip the data record and find the next object at offset 8468 instead of offset 272. I have successfully tested this by sending the SPACE(6) command that was revealing the bug to a simh file with the in-process test tool on my PC:

>./bin/in_process_tool -s "-i 0 simh.tap"
...
s2pexec>-i 0 -L trace -c 11:00:00:7f:ff:00
...
[19:46:42.782] [debug] (ID 0) - Controller is executing SPACE(6), CDB 11:00:00:7f:ff:00
[19:46:42.782] [debug] (ID:LUN 0:0) - Device is executing SPACE(6) ($11)
[19:46:42.782] [trace] (ID:LUN 0:0) - Read SIMH header with class 0, value $0002000 at position 268
[19:46:42.782] [trace] (ID:LUN 0:0) - Searching for object type 0, found type 0 at position 268
[19:46:42.782] [trace] (ID:LUN 0:0) - Read SIMH header with class 0, value $0002000 at position 8468
[19:46:42.782] [trace] (ID:LUN 0:0) - Searching for object type 0, found type 0 at position 8468
...

The purpose of this SPACE(6) is to skip up to $7fff data records until a filemark (called tape mark in the simh notation) is found. I guess this is because for a directory listing the data records are not relevant. Filename information appears to be stored in the smaller 80 byte blocks, and a series of these blocks is marked with a filemark.

@Pacjunk
Copy link

Pacjunk commented Nov 15, 2024

Only a little testing today - got a migraine!

Anyway, the directory listing seems to have worked correctly :
dir good.txt

I tried to copy the first (small) file off the tape (VMS054.A), but this failed:
copy bad.txt

I think I am using http://www.bitsavers.org/bits/DEC/vax/vms/TK50/aq-jp22f-be_vms_v5.4_bin_1of2_1990.tap for the data. Can't be 100% sure though - the file name is different. I downloaded it a long time ago.

@uweseimet
Copy link
Owner Author

uweseimet commented Nov 15, 2024

So there is gradual progress. I always need to know the commit ID your tests are based on, please remember this.

Your log reveals an issue with the block size:

[2024-11-15 18:23:08.206] [debug] (ID 3) - Controller is executing READ(6)/GET MESSAGE(6), CDB 08:00:00:20:00:00
[2024-11-15 18:23:08.207] [debug] (ID:LUN 3:0) - Device is executing READ(6)/GET MESSAGE(6) ($08)
[2024-11-15 18:23:08.207] [trace] (ID:LUN 3:0) - Current position: 268, requested byte count: 8192
[2024-11-15 18:23:08.208] [trace] (ID:LUN 3:0) - Read SIMH header with class 0, value $0002000 at position 268
[2024-11-15 18:23:08.208] [trace] (ID:LUN 3:0) - Searching for object type 0, found type 0 at position 268
[2024-11-15 18:23:08.209] [trace] (ID:LUN 3:0) - Actual block length of 8192 byte(s) does not match expected length of 512 byte(s)
[2024-11-15 18:23:08.209] [debug] (ID 3) - MEDIUM ERROR (Sense Key $03), NO ADDITIONAL_SENSE INFORMATION (ASC $00), ASCQ $00

Your system expects a default block size of 8192 bytes. The latest issue_100 branch supports this. Please test again after updating your sources and re-compiling. Ensure that your emulated tape uses a block size of 8192 bytes by adding "-b 8192" to the device parameters when you launch s2p.

If you are not sure which file you are using, please re-download it and compare it with your renamed file (e.g. with diff or bcmp), or use a different file. We have to ensure that I use the same file as you for my tests. As soon as it is ensured that we are using the same file, I would be interested in how the directory listing looks like.
As you can see in my last comment I can replay the commands used by your driver with the in_process_tool, but I have to do this on the same file as your driver in order to get meaningful results.

When you say that you copy a file off the tape, I assume this is equivalent to what "tar xf" does, i.e. extracting the archive contents and writing them to the filesystem?

@Pacjunk
Copy link

Pacjunk commented Nov 15, 2024

Sorry, but I didnt get the build number. It was the current version immediately prior to my testing.

I have confirmed that the link for the .tap file above is the correct one. The directory listing dump is against that file.

The tape contains "save sets", which in unix speak is an uncompressed tar. I believe the default record size for these is 8192, but I believe it is configurable up to 32256. I will check the documentation.

I tried to copy one of these "tar" files off the tape, not extract it. This is an allowed operation.

Tapes can be mounted in the files11 format (which is what I have done), then the files can be operated on like any other disk files (except no directories). They can also be mounted as "foreign", which is for interchange with other systems or for creating/extracting these save sets directly.

The first format is the easiest if you just want to copy a handful of files on or off the tape without having to worry about packing them up into a saveset. The latter is better when you have thousands of files to copy.

@uweseimet
Copy link
Owner Author

uweseimet commented Nov 15, 2024

@Pacjunk Thank you for providing information on the copy operation.

The newer the device, the bigger the supported block sizes appear to be. Current drives support sizes of 512 KB or maybe even more. With SCSI hard drives and MOD SELECT, or with the "-b" option, any size that is a multiple of 4 can be set up to the maximum supported size, which for tape drives is 8192 bytes now.

I will try to find out whether your driver tries to change the block size with one of the MODE SELECT commands it sends, but for now using "-b 8192" enforces the required size manually.

You can use "git log --abbrev-commit" to get the current commit ID of your checked out git branch, by the way.

@Pacjunk
Copy link

Pacjunk commented Nov 15, 2024

Checked the doco. You can specify a block size between 2048 and 65,535 bytes. and also The default block size for magnetic tape is 8192 bytes; the default for disk is 32,256 bytes. This is where I heard the 32256 figure. I believe if you create the save set (tar) on disk, then copy to tape it will be 32256. If written directly to tape, then 8192. The .tap files we are dealing with have been written directly to tape so 8192 should be fine.

Of course this block size is that within the file container. Standard on disk block size is still 512. (and 2048 for tapes)

@uweseimet
Copy link
Owner Author

uweseimet commented Nov 15, 2024

@Pacjunk Thank you for checking this. I will try to make the SCSI2Pi block size support even more flexible than it already is. But for your next test the issue_100 branch is already prepared.

I checked the MODE SELECT statements: Your driver does not try to change the block size. But I missed that your driver does NOT set the Fixed flag in the READ(6) command, i.e. it explicitly tells the drive how many bytes to read: 8192.
For your testing this means that despite of what I said before, with the latest issue_100 branch you should not need the "-b 8192" option. Please first run a test without this option, just like your tests before. Only if this test fails, run your test a second time with the "-b 8192" option.

Regarding log files, as long as the "dir" test does not fail there is no need to attach a log for the "dir" test.
From now on, please always add -l "[%l] %v" to your s2p startup options. This log pattern will make the log files more compact and easier to read because it removes the timestamps, which are irrevelant for these tests. You can also set the pattern permanently in /etc/s2p.conf with:

log_pattern=[%l] %v

@uweseimet
Copy link
Owner Author

uweseimet commented Nov 15, 2024

Except for having to be a multiple of 4 bytes (according to the SCSI standard) the tape drive block size is now completely flexible. When there are read/write requests for any block size (this size can be bigger than the default block size), s2p transfers and reads/writes the data in multiples of the default block size. This is reflected in the log: The bigger the default tape block size, the less read/write operations are needed. But the final result is always the same.
For 8192 byte records in a simh file this means that when the SCTP device block size is 512 bytes, s2p splits the 8192 byte transfer into 16 chunks. When the SCTP device block size is 8192 bytes, a record is transferred in a single chunk, yielding the same effective result. For the user this is fully transparent.

@Pacjunk
Copy link

Pacjunk commented Nov 16, 2024

I cannot compile now. I start the compilation and it goes for probably 90 minutes on the one file then:

g++ -O0 -g -DDEBUG -std=c++20 -iquote . -D_FILE_OFFSET_BITS=64 -DFMT_HEADER_ONLY -DSPDLOG_FMT_EXTERNAL -MD -MP -Wall -Wextra -Wno-psabi  -DBOARD_FULLSPEC -DBUILD_SCHD -DBUILD_SCMO -DBUILD_SCCD -DBUILD_SCTP -DBUILD_SCDP -DBUILD_SCLP -DBUILD_SCHS -DBUILD_SAHD -DBUILD_STORAGE_DEVICE -DBUILD_DISK -c command/command_dispatcher.cpp -o obj/command_dispatcher.o
g++: fatal error: Killed signal terminated program cc1plus
compilation terminated.

It seems to use most of the CPU and memory.

I followed your installation instructions and added: export CXXFLAGS="clang++"
This just generated errors as it just adds clang++ as a parameter, so you get "g++ clang++ ..." and of course g++ doesn't know what to do with this.

I tried grabbing one of the build lines and substituted g++ with clang++ and this worked to build that one module.

I don't know enough about makefiles to understand how to fix this, so I just edited the Makefile to change g++ to clang++

I'm yet to see if this works.

@Pacjunk
Copy link

Pacjunk commented Nov 16, 2024

Build seems to complete (although it seemed to rebuild nearly everything). I will test later...

@Pacjunk
Copy link

Pacjunk commented Nov 16, 2024

Well that went badly - Can't even mount the tape now (can't find the label). Build c826343

Blocksize unset :
mount1.txt

Blocksize set to 8k :
mount8k.txt

@uweseimet
Copy link
Owner Author

uweseimet commented Nov 16, 2024

[trace] (ID:LUN 3:0) - Read SIMH header with class 0, value $0000000 at position 264
[debug] (ID 3) - MEDIUM ERROR (Sense Key $03), READ ERROR (ASC $11), ASCQ $00

I'll check this.

Regarding clang++ I just updated the Wiki:

make CXX=clang++

Using clang++ instead of g++ compiles faster. I always use clang++ except for building the binary distributions. Note that after changing the compiler running "make clean" is required.

@uweseimet
Copy link
Owner Author

uweseimet commented Nov 16, 2024

Well that went badly - Can't even mount the tape now (can't find the label). Build c826343

This should be fixed with the latest issue_100 branch. I could reproduce this problem with the in process test tool and the same .tap file that you are using. For the test I extracted all commands sent by your test and prefixed them with "-c " (for use with the tool) with

sed -n "s/.*CDB \(.*\)$/-c \1/p" LOGFILE.txt

I removed all commands that are irrelevant for this test like INQUIRY or TEST UNIT READY and set up a sequence of commands in a file "simh.tst" with this content:

-i 0 -L trace
-c 08:00:00:00:50:00
-c 08:00:00:00:50:00
-c 08:00:00:00:50:00
-c 08:00:00:00:50:00
-c 11:00:00:7f:ff:00
-c 08:00:00:00:50:00

I run the test on my Linux PC with

./bin/in_process_tool -s "-i 0 simh.tap" < simh.tst

This way I send the commands in the simh.tst file to s2p. This produces essentially the same s2p logfile as your test, and I can compare the results. In the case of the issue you reported I can see that with the fixed issue_100 branch the results appear to be correct again. Let's see whether your system confirms that ;-).

@Pacjunk
Copy link

Pacjunk commented Dec 1, 2024

f46f108
Some tests with foreignlist. Note I can't start with a blank file because I cannot write any files to the emulated tape drive yet! I can initialise the tape, but the command I use reads a file on the tape, and that file cannot exist as we haven't got to the stage of writing files yet.

Running the output script on a real tape. This tape is not and cannot be identical, but has the same contents.
foreignlist script exec.txt

Script output:
foreignlist script.txt

s2p output:
foreignlist.txt

@Pacjunk
Copy link

Pacjunk commented Dec 1, 2024

If I initialise a blank (zeroed) file, I get the following:

Offset 0 ($0): Class 0, good data record, record length 80 ($50)
Offset 88 ($58): Class 0, good data record, record length 80 ($50)
Offset 176 ($b0): Class 0, good data record, record length 80 ($50)
Offset 264 ($108): Class 0, tape mark
Offset 268 ($10c): Class 0, tape mark
Offset 272 ($110): Class 0, good data record, record length 80 ($50)
Offset 360 ($168): Class 0, good data record, record length 80 ($50)
Offset 448 ($1c0): Class 0, tape mark
Offset 452 ($1c4): Class 0, tape mark
Offset 456 ($1c8): Class 7, private marker (SCSI2Pi end-of-data object)

As far as I know, the double tape mark signifies the end of the tape, so why is there more data after the double tape mark?
The data seems like valid entries:

Offset 0 ($0): Class 0, good data record, record length 80 ($50)
00000000  56:4f:4c:31:54:45:53:54:20:20:20:20:20:20:20:20  'VOL1TEST        '
00000010  20:20:20:20:20:20:20:20:20:20:20:20:20:20:20:20  '                '
00000020  20:20:20:20:20:20:20:20:20:20:20:20:20:20:20:20  '                '
00000030  20:20:20:20:20:20:20:20:20:20:20:20:20:20:20:20  '                '
00000040  20:20:20:20:20:20:20:20:20:20:20:20:20:20:20:33  '               3'
Offset 88 ($58): Class 0, good data record, record length 80 ($50)
00000000  48:44:52:31:20:20:20:20:20:20:20:20:20:20:20:20  'HDR1            '
00000010  20:20:20:20:20:54:45:53:54:20:20:30:30:30:31:30  '     TEST  00010'
00000020  30:30:30:30:30:30:31:30:30:30:32:34:33:33:36:30  '0000001000243360'
00000030  32:34:33:33:36:20:30:30:30:30:30:30:44:45:43:46  '24336 000000DECF'
00000040  49:4c:45:31:31:41:20:20:20:20:20:20:20:20:20:20  'ILE11A          '
Offset 176 ($b0): Class 0, good data record, record length 80 ($50)
00000000  48:44:52:32:46:30:30:30:30:30:30:30:30:30:30:20  'HDR2F0000000000 '
00000010  20:20:20:20:20:20:20:20:20:20:20:20:20:20:20:20  '                '
00000020  20:20:20:20:20:20:20:20:20:20:20:20:20:20:20:20  '                '
00000030  20:20:30:30:20:20:20:20:20:20:20:20:20:20:20:20  '  00            '
00000040  20:20:20:20:20:20:20:20:20:20:20:20:20:20:20:20  '                '
Offset 264 ($108): Class 0, tape mark
Offset 268 ($10c): Class 0, tape mark
Offset 272 ($110): Class 0, good data record, record length 80 ($50)
00000000  45:4f:46:31:20:20:20:20:20:20:20:20:20:20:20:20  'EOF1            '
00000010  20:20:20:20:20:54:45:53:54:20:20:30:30:30:31:30  '     TEST  00010'
00000020  30:30:30:30:30:30:31:30:30:30:32:34:33:33:36:30  '0000001000243360'
00000030  32:34:33:33:36:20:30:30:30:30:30:30:44:45:43:46  '24336 000000DECF'
00000040  49:4c:45:31:31:41:20:20:20:20:20:20:20:20:20:20  'ILE11A          '
Offset 360 ($168): Class 0, good data record, record length 80 ($50)
00000000  45:4f:46:32:46:30:30:30:30:30:30:30:30:30:30:20  'EOF2F0000000000 '
00000010  20:20:20:20:20:20:20:20:20:20:20:20:20:20:20:20  '                '
00000020  20:20:20:20:20:20:20:20:20:20:20:20:20:20:20:20  '                '
00000030  20:20:30:30:20:20:20:20:20:20:20:20:20:20:20:20  '  00            '
00000040  20:20:20:20:20:20:20:20:20:20:20:20:20:20:20:20  '                '
Offset 448 ($1c0): Class 0, tape mark
Offset 452 ($1c4): Class 0, tape mark
Offset 456 ($1c8): Class 7, private marker (SCSI2Pi end-of-data object)

You are not writing two tape marks instead of one?

@uweseimet
Copy link
Owner Author

uweseimet commented Dec 1, 2024

The private end-of-data marker is automatically created by s2p. The two tape marks written by your driver are specific to your driver. s2p may not assume these to always be there and have a particular meaning. tar and drivers for other platforms handle this differently.
The marker is mapped to a SCSI end-of-data object.

Regarding a blank file: What I meant is that it should be empty before you initialize it. This means it should not contain anything else but the well-defined data you have dumped above before you run your tests. The two tape marks are created by your driver (init script).

I will get back to you as soon as I have analyzed the latest logs.

@Pacjunk
Copy link

Pacjunk commented Dec 1, 2024

I did give the build number (beginning of post)

and the file I initialised was blank - as I stated.

@uweseimet
Copy link
Owner Author

Yes, I just noticed that. I'm sorry for missing it.

@uweseimet
Copy link
Owner Author

uweseimet commented Dec 1, 2024

Regarding your test, the sense data returned by your drive include custom information not covered by the SCSI specification. I have tweaked s2p to also return some of these data, let's see what happens.
Please update your issue_100 sources and run the test again.

@Pacjunk
Copy link

Pacjunk commented Dec 3, 2024

Build f15e373

I've changed to the Pi 3B - sick of 3 hour+ rebuilds due to low memory. Seems to run s2p faster as well!

No real change in latest logs. Attached...
foreignlist.txt
foreignlist script.txt

@uweseimet
Copy link
Owner Author

uweseimet commented Dec 3, 2024

Yes, the transfer rates depend on the CPU and on how fast/how often per time unit the GPIO port can be accessed. The latter is probably even more important than the CPU. I have optimized this, which in one reason for the higher throughput then with the PiSCSI software.

Regarding your test I am still unsure what the relevant difference between s2p and your drive is. Can you please run this script with s2pexec against your drive?

-L trace -i 3:0
-c 12:00:00:00:ff:00
-c 00:00:00:00:00:00
-c 0a:00:00:00:04:00 -d 01:02:03:04 -o 90
-c 0a:00:00:00:04:00 -d 01:02:03:04 -o 90
-c 0a:00:00:00:04:00 -d 01:02:03:04 -o 90
-c 11:00:ff:ff:fe:00 -o 90
-c -n 08:00:00:00:20:00 -o 90
-c 03:00:00:00:ff:00

It is slightly different than the one before wrt getting the sense data. If you can also run it against a different tape drive it would help to find out whether vendor-specific information is returned.

@Pacjunk
Copy link

Pacjunk commented Dec 3, 2024

Here you go...
test.txt

It is not easy for me to get the other tape drive at the moment. Maybe tomorrow...

@uweseimet
Copy link
Owner Author

uweseimet commented Dec 3, 2024

Thank you. Tomorrow (or later) is no problem at all. The reason why I am asking is that your Sony drive returns non-standard data with some error details. Non-standard means that the SCSI specs say that the format used is correct, but a custom one. Reading 90 bytes when only 80 are available is such a case. Testing this with a different drive might provide more insight on the error handling.

Regarding your latest log: Can it be that the tape is write-protected? The log says so, but for this script writing is required.
Nevertheless, the log is interesting because it also has custom information in it in the error reporting:

00000000  f0:00:07:00:00:00:04:12:00:00:00:00:27:00:00:00  '............'...'
00000010  00:00:00:00:00:00:00:3a:93:10
...
00000000  f0:00:40:00:00:00:02:12:00:00:00:00:00:04:00:00  '..@.............'
00000010  05:00:00:00:00:00:00:3a:94:ea

The last three bytes are the ones I stumble upon.

@Pacjunk
Copy link

Pacjunk commented Dec 3, 2024

Yes, the tape was write protected. I assumed you were doing a test similar to the foreignlist test which was only reading the tape - and I don't want some strange script corrupting that tape. I will re-run the test with a scratch tape.

Try this:
test_writable.txt

@uweseimet
Copy link
Owner Author

uweseimet commented Dec 3, 2024

Thank you. I'm afraid there was a typo in the script. Can you please try again with:

-L trace -i 3:0
-c 12:00:00:00:ff:00
-c 00:00:00:00:00:00
-c 0a:00:00:00:04:00 -d 01:02:03:04 -o 90
-c 0a:00:00:00:04:00 -d 01:02:03:04 -o 90
-c 0a:00:00:00:04:00 -d 01:02:03:04 -o 90
-c 11:00:ff:ff:fe:00 -o 90
-n -c 08:00:00:00:20:00 -o 90
-c 03:00:00:00:ff:00

The -n suppresses the automatic REQUEST SENSE, which is run explicitly at the end.

@Pacjunk
Copy link

Pacjunk commented Dec 3, 2024

test_writable2.txt

@uweseimet
Copy link
Owner Author

uweseimet commented Dec 3, 2024

Now it's fine. Again with some custom bytes at the end:

00000000  f0:00:20:00:00:00:1c:12:00:00:00:00:00:00:00:00  '.. .............'
00000010  ca:00:00:00:00:00:00:1d:1e:3a                    '.........:'

I have to figure out what to do next. If this is the only difference between what your drive does with this script and what s2p does, I will temporarily tweak s2p to return excactly the same data, assuming that your driver will proceed then, becasue it receives the same data as will your real drive.
I will also compare these data with what my partially working drive reports with the same script.

@Pacjunk
Copy link

Pacjunk commented Dec 3, 2024

I know I have asked this before, but is it possible to have a program that just records the traffic between the initiator and a nominated SCSI ID? That way you could get a snapshot of the two way conversation involved with a real drive and see if s2p does similar?

@uweseimet
Copy link
Owner Author

uweseimet commented Dec 3, 2024

As already mentioned, in theory the scsimon tool (PiSCSI) might do that. In practice I doubt that it works, because your computer and drive will likely communicate faster than the Pi can record the data. Or they might even use synchronous transfers, which the Pi would not be able to log at all. But you can give it a try. You will probably get a very verbose log with some (but not all) of the data on the bus.
scsimon definitely does not give you the structured output you get with the s2p/s2pexec logs.

But all commands and data sent are logged in the s2p and s2pexec logs. There is nothing else, i.e. recording the traffic would not reveal more information. Also in practice, so far nothing has been missing, and using scripts with s2p and s2pexec has yielded consistent and comparable results. Everything that has not worked in the past was confirmed/revealed by the logs and scripts.

@Pacjunk
Copy link

Pacjunk commented Dec 3, 2024

Just ran it. Don't know what the data means. I think one file is signal waveforms, and html file looks more readable but is severely lacking detail.

@uweseimet
Copy link
Owner Author

uweseimet commented Dec 3, 2024

I compared the two logs: Except for the additional sense data returned by your drive when 90 instead of the available 80 bytes are read the command executions are identical. This means that either the additional data are relevant, or it is something else that happened before in foreign test, which I have missed. But there is not that much happening in this test, and it stops right after the different error data were returned.
The latest issue_100 sources contain a tweak so that s2p returns exactly the same data as your drive:

00000000  f0:00:20:00:00:00:1c:12:00:00:00:00:00:00:00:00  '.. .............'
00000010  ca:00:00:00:00:00:00:1d:1e:3a                    '.........:'

If the test fails again, please run the last test script again, twice, against your drive. I want to ensure that these custom data are not something random but always the same.

@Pacjunk
Copy link

Pacjunk commented Dec 4, 2024

Build 18a0306

Still a problem:
foreignlist.txt
foreignlist script.txt

I'm beginning to wonder if this is a tape position issue. When the tape is mounted foreign, subsequent commands don't rewind the tape, but just continue on from the last position. The mount itself does a rewind, and if I force a rewind manually the results are the same. The command to list the tapes' content complains that it has an invalid label, so maybe the "resting place" after a rewind is not correct?

Mounting the tape "non-foreign" works fine, but its probably doing everything in one operation. ie rewinding, then loading data, whereas with foreign, the rewind and the read are part of different commands.

@uweseimet
Copy link
Owner Author

uweseimet commented Dec 4, 2024

The tape position is a good point, indeed. I am not sure what this means for testing, though. Which sequence of scripts or command would be the required one? When you use your real tape, what is the matching sequence of scripts/commands? What I mean is, when you run the foreign mount operation with your drive, which operations were run before? We already have scripts for everything, don't we?
In other words, when you mount the tape with your real hardware, which step ensures the correct tape position? There would either have to be a rewind or a SPACE command somewhere.
Therefore, running an isolated foreign test without nothing else before is probably not a valid scenario.

@uweseimet
Copy link
Owner Author

@Pacjunk This ticket is dealing with SIMH file support, but this has already been implemented and we are now dealing with other issues. In addition, I am losing track of all the scripts, logs etc. attached to this ticket.
I would like to close this ticket and create a more specific one on the problems we are facing. Can you please provide the name of your workstation and driver etc. so that I can set up a more specific ticket. You may have provided this information in the past, but it has become hard to find information in this ticket.

@Pacjunk
Copy link

Pacjunk commented Dec 4, 2024

According to the trace log the last thing the mount/foreign command does is a rewind, so it should be ready for the next command (that we have been analysing). The message the OS gives when trying to list the contents is "tape is not valid ANSI format" - so its obviously trying to look for the ansi field markers e.g. VOL1, HDR1 etc

Is there a way to get the trace dump to display the contents of the data read? ie the 80 or 90 bytes. Then we could see if the data aligns with those field markers.

I'm testing on a VAXstation 3100 running OpenVMS 7.2.

@uweseimet
Copy link
Owner Author

uweseimet commented Dec 4, 2024

The trace dumps already display the contents, as long as there is no mismatch between the byte count. Otherwise they cannot display any content because the READ command terminates with an error message.
If you have read 80 bytes and the block size matches these 80 bytes you get this dump on trace level:

00000000  56:4f:4c:31:54:45:53:54:33:33:20:20:20:20:20:20  'VOL1TEST33      '
00000010  20:20:20:20:20:20:20:20:20:20:20:20:20:20:20:20  '                '
00000020  20:20:20:20:20:20:20:20:20:20:20:20:20:20:20:20  '                '
00000030  20:20:20:20:20:20:20:20:20:20:20:20:20:20:20:20  '                '
00000040  20:20:20:20:20:20:20:20:20:20:20:20:20:20:20:33  '               3'

You get the same output when running s2psimh on the same image file:

>s2psimh -d ~/hatari/test.tap
Offset 0 ($0): Class 0, good data record, record length 80 ($50)
00000000  56:4f:4c:31:54:45:53:54:33:33:20:20:20:20:20:20  'VOL1TEST33      '
00000010  20:20:20:20:20:20:20:20:20:20:20:20:20:20:20:20  '                '
00000020  20:20:20:20:20:20:20:20:20:20:20:20:20:20:20:20  '                '
00000030  20:20:20:20:20:20:20:20:20:20:20:20:20:20:20:20  '                '
00000040  20:20:20:20:20:20:20:20:20:20:20:20:20:20:20:33  '               3'

Everything is IMO consistent here, i.e. for a given position on the tape s2p reads and displays the same data as s2psimh.
The first read command of the foreign test tries to read 90 bytes, but the image file starts with an 80 byte block. This means that s2p reports an error, and your real tape drive reports the same error, with some custom bytes in the sense data.

@uweseimet
Copy link
Owner Author

@Pacjunk I created #111 in order to deal with testing with your hardware.

@uweseimet
Copy link
Owner Author

@Pacjunk There is a new issue_111 branch now, which replaces the issue_100 branch for testing. Please run "git pull" and then "git checkout issue_111". Currently, issue_111 is identical with issue_100. Any further commits will go to issue_111.

@uweseimet uweseimet moved this to In progress in SCSI2Pi release 5.0 Dec 12, 2024
@uweseimet uweseimet moved this from In progress to Done in SCSI2Pi release 5.0 Dec 12, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
enhancement New feature or request help wanted Extra attention is needed
Projects
No open projects
Status: Done
Development

No branches or pull requests

2 participants