uweseimet / scsi2pi

Advanced performant SCSI/SASI emulation and tools for the PiSCSI/RaSCSI board
https://www.scsi2pi.net
BSD 3-Clause "New" or "Revised" License
10 stars 2 forks source link

Amiga - CD Rom Devices do not work #92

Closed SavourySnaX closed 4 months ago

SavourySnaX commented 4 months ago

When creating a new ticket please provide information on your environment.

Describe the issue

Tried installing the 3.4 release to see if it was a suitable replacement for the piscsi v24.04.01 release, I have a lot of devices in the config for the device. With 2 cd roms (Units 6 0 and 6 1), on the piscsi drivers the 2 cdroms are mounted and behave correctly, on the scsi2pi 3.4 release, the cd roms mount incorrectly, 1 detects as audio cd (its purely data), the other behaves even more strangely (and causes standard amiga assigns to be lost). reverting back to piscsi and the devices return to normal behaviour.

I can do further testing, if there is something specific i can enable to trace the issues i may be willing. I've only tried 3.4, I could bisect the releases if it would help. My time is limited however, so it might be a few weekends before I can do that.

uweseimet commented 4 months ago

Bisecting would not really help because the SCSI2Pi repository does not contain the legacy PiSCSI codebase, and due to numerous new features and cleanups it differs quite a lot from PiSCSI anyway.

I don't have an Amiga, but I might be able to figure out what's wrong if you can provide the images of your CD-ROMs. One image is enough for a start, because a step-by-step approach is best. I would also be interested in logs showing what happens when you mount/access this image with PiSCSI and with SCSI2Pi. When testing, please only attach one of the affected images, not both. When the issue is resolved for one image, the other can be addressed. Otherwise the test setup and the logs are too complicated. Having as few devices as possible when debugging make things easier.

In case you don't have time yet for providing logs but can already provide an image, this might already get me started.

uweseimet commented 4 months ago

Instead of providing an image, running this command on your image file and attaching the resulting file "test.img" may already be sufficient:

dd of=test.img if=YOUR_IMAGE_FILE count=4
SavourySnaX commented 4 months ago

The output from the above command is a file with all 00's in it, these are straightforward .iso images, the first 32k in both cases are 0's (ISO_9660), so I dumped the first 64k from one, in case that is more useful. test.zip

I`ll try and get the logs shortly.

SavourySnaX commented 4 months ago

From piscsi (when mounting device) :

Jul 22 16:04:22 raspberrypi PISCSI[346]: [2024-07-22 16:04:22.222] [debug] (ID:LUN 6:0) - Device is executing ReadToc ($43)
Jul 22 16:04:22 raspberrypi PISCSI[346]: [2024-07-22 16:04:22.229] [debug] (ID:LUN 6:0) - Device is executing ReadToc ($43)
Jul 22 16:04:22 raspberrypi PISCSI[346]: [2024-07-22 16:04:22.236] [debug] (ID:LUN 6:0) - Device is executing ReadToc ($43)
Jul 22 16:04:22 raspberrypi PISCSI[346]: [2024-07-22 16:04:22.247] [debug] (ID:LUN 6:0) - Device is executing ReadToc ($43)
Jul 22 16:04:22 raspberrypi PISCSI[346]: [2024-07-22 16:04:22.249] [debug] (ID:LUN 6:0) - Device is executing ReadToc ($43)
Jul 22 16:04:22 raspberrypi PISCSI[346]: [2024-07-22 16:04:22.251] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:04:22 raspberrypi PISCSI[346]: [2024-07-22 16:04:22.262] [debug] (ID:LUN 6:0) - Device is executing ReadToc ($43)
Jul 22 16:04:22 raspberrypi PISCSI[346]: [2024-07-22 16:04:22.264] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:04:22 raspberrypi PISCSI[346]: [2024-07-22 16:04:22.274] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:04:22 raspberrypi PISCSI[346]: [2024-07-22 16:04:22.301] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:04:22 raspberrypi PISCSI[346]: [2024-07-22 16:04:22.317] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:04:22 raspberrypi PISCSI[346]: [2024-07-22 16:04:22.330] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:04:22 raspberrypi PISCSI[346]: [2024-07-22 16:04:22.365] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:04:23 raspberrypi PISCSI[346]: [2024-07-22 16:04:23.692] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:04:26 raspberrypi PISCSI[346]: [2024-07-22 16:04:26.712] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:04:29 raspberrypi PISCSI[346]: [2024-07-22 16:04:29.732] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:04:32 raspberrypi PISCSI[346]: [2024-07-22 16:04:32.752] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)

Device Appears correctly (AmigaOS3.2 volume label with contents)

From scsi2pi :

[2024-07-22 16:14:52.201] [debug] (ID 6) - Controller is executing READ TOC, CDB $43:02:02:00:00:00:00:04:50:00
[2024-07-22 16:14:52.203] [debug] (ID:LUN 6:0) - Device is executing READ TOC ($43)
[2024-07-22 16:14:52.211] [debug] (ID 6) - Controller is executing READ TOC, CDB $43:00:00:00:00:00:00:03:24:00
[2024-07-22 16:14:52.214] [debug] (ID:LUN 6:0) - Device is executing READ TOC ($43)
[2024-07-22 16:14:52.219] [debug] (ID 6) - Controller is executing READ TOC, CDB $43:00:05:00:00:00:00:07:1e:00
[2024-07-22 16:14:52.220] [debug] (ID:LUN 6:0) - Device is executing READ TOC ($43)
[2024-07-22 16:14:53.169] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:14:53.170] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)

Device appears as audioCD_0100000000 (volume label - contents empty)

uweseimet commented 4 months ago

Can you please log on trace level?

SavourySnaX commented 4 months ago

Trace logs for scsi2pi :

[2024-07-22 16:21:00.440] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:21:00.442] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:21:00.442] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:21:00.442] [trace] (ID 6) - All data transferred
[2024-07-22 16:21:00.443] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:21:00.443] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:21:00.444] [trace] (ID 6) - All data transferred
[2024-07-22 16:21:00.447] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:21:00.448] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:21:00.449] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:21:00.449] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:21:00.450] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:21:00.450] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:21:00.451] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:21:00.451] [debug] (ID 6) - Controller is executing READ TOC, CDB $43:02:02:00:00:00:00:04:50:00
[2024-07-22 16:21:00.451] [debug] (ID:LUN 6:0) - Device is executing READ TOC ($43)
[2024-07-22 16:21:00.453] [trace] (ID 6) - DATA IN phase
[2024-07-22 16:21:00.454] [trace] (ID 6) - Sending 12 byte(s)
[2024-07-22 16:21:00.454] [trace] (ID 6) - All data transferred
[2024-07-22 16:21:00.455] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:21:00.456] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:21:00.457] [trace] (ID 6) - All data transferred
[2024-07-22 16:21:00.457] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:21:00.459] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:21:00.460] [trace] (ID 6) - All data transferred
[2024-07-22 16:21:00.461] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:21:00.463] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:21:00.463] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:21:00.464] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:21:00.464] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:21:00.464] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:21:00.465] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:21:00.465] [debug] (ID 6) - Controller is executing READ TOC, CDB $43:00:00:00:00:00:00:03:24:00
[2024-07-22 16:21:00.466] [debug] (ID:LUN 6:0) - Device is executing READ TOC ($43)
[2024-07-22 16:21:00.467] [trace] (ID 6) - DATA IN phase
[2024-07-22 16:21:00.468] [trace] (ID 6) - Sending 12 byte(s)
[2024-07-22 16:21:00.470] [trace] (ID 6) - All data transferred
[2024-07-22 16:21:00.470] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:21:00.471] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:21:00.473] [trace] (ID 6) - All data transferred
[2024-07-22 16:21:00.473] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:21:00.475] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:21:00.475] [trace] (ID 6) - All data transferred
[2024-07-22 16:21:00.475] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:21:00.480] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:21:00.480] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:21:00.480] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:21:00.480] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:21:00.480] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:21:00.481] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:21:00.481] [debug] (ID 6) - Controller is executing READ TOC, CDB $43:00:05:00:00:00:00:07:1e:00
[2024-07-22 16:21:00.482] [debug] (ID:LUN 6:0) - Device is executing READ TOC ($43)
[2024-07-22 16:21:00.482] [trace] (ID 6) - DATA IN phase
[2024-07-22 16:21:00.483] [trace] (ID 6) - Sending 12 byte(s)
[2024-07-22 16:21:00.484] [trace] (ID 6) - All data transferred
[2024-07-22 16:21:00.485] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:21:00.486] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:21:00.487] [trace] (ID 6) - All data transferred
[2024-07-22 16:21:00.488] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:21:00.489] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:21:00.489] [trace] (ID 6) - All data transferred
[2024-07-22 16:21:00.490] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:21:02.164] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:21:02.164] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:21:02.165] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:21:02.165] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:21:02.165] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:21:02.165] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:21:02.165] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:21:02.165] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:21:02.167] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:21:02.167] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:21:02.167] [trace] (ID 6) - All data transferred
[2024-07-22 16:21:02.168] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:21:02.168] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:21:02.168] [trace] (ID 6) - All data transferred
[2024-07-22 16:21:02.169] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:21:05.184] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:21:05.185] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:21:05.186] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:21:05.186] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:21:05.186] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:21:05.187] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:21:05.187] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:21:05.187] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:21:05.187] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:21:05.188] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:21:05.189] [trace] (ID 6) - All data transferred
[2024-07-22 16:21:05.191] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:21:05.192] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:21:05.193] [trace] (ID 6) - All data transferred
[2024-07-22 16:21:05.194] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:21:08.204] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:21:08.204] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:21:08.204] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:21:08.204] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:21:08.204] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:21:08.204] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:21:08.205] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:21:08.205] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:21:08.205] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:21:08.205] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:21:08.205] [trace] (ID 6) - All data transferred
[2024-07-22 16:21:08.205] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:21:08.205] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:21:08.205] [trace] (ID 6) - All data transferred
[2024-07-22 16:21:08.205] [trace] (ID 6) - BUS FREE phase
uweseimet commented 4 months ago

Thank you. I would also like to request the piscsi trace logs for the same operation.

SavourySnaX commented 4 months ago

piscsi version :

Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.951] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.952] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.952] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.952] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.952] [trace] (ID 6) - Message In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.952] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.952] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.952] [trace] (ID 6) - Bus Free phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.953] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.953] [trace] (ID 6) - Selection phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.953] [trace] (ID 6) - Selection completed
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.953] [trace] (ID 6) - Message Out phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.953] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.953] [trace] (ID 6) - Phase: msgout
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.953] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.953] [trace] (ID 6) - Command phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.954] [trace] (ID 6) - Controller is executing ReadToc, CDB $43020200000000045000
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.954] [debug] (ID:LUN 6:0) - Device is executing ReadToc ($43)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.954] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.954] [trace] (ID 6) - Data In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.954] [trace] (ID 6) - Sending data, offset: 0, length: 1104
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.959] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.959] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.959] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.959] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.959] [trace] (ID 6) - Message In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.959] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.960] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.960] [trace] (ID 6) - Bus Free phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.960] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.960] [trace] (ID 6) - Selection phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.960] [trace] (ID 6) - Selection completed
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.961] [trace] (ID 6) - Message Out phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.961] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.961] [trace] (ID 6) - Phase: msgout
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.961] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.961] [trace] (ID 6) - Command phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.961] [trace] (ID 6) - Controller is executing ReadToc, CDB $43000000000000032400
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.961] [debug] (ID:LUN 6:0) - Device is executing ReadToc ($43)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.961] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.961] [trace] (ID 6) - Data In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.961] [trace] (ID 6) - Sending data, offset: 0, length: 804
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.965] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.965] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.965] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.966] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.966] [trace] (ID 6) - Message In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.966] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.966] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.966] [trace] (ID 6) - Bus Free phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.969] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.969] [trace] (ID 6) - Selection phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.969] [trace] (ID 6) - Selection completed
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.969] [trace] (ID 6) - Message Out phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.969] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.969] [trace] (ID 6) - Phase: msgout
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.969] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.969] [trace] (ID 6) - Command phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.969] [trace] (ID 6) - Controller is executing ReadToc, CDB $43000500000000071e00
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.969] [debug] (ID:LUN 6:0) - Device is executing ReadToc ($43)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.969] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.970] [trace] (ID 6) - Data In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.970] [trace] (ID 6) - Sending data, offset: 0, length: 1822
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.978] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.978] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.978] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.978] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.978] [trace] (ID 6) - Message In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.978] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.979] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.979] [trace] (ID 6) - Bus Free phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.980] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.980] [trace] (ID 6) - Selection phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.980] [trace] (ID 6) - Selection completed
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.980] [trace] (ID 6) - Message Out phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.980] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.980] [trace] (ID 6) - Phase: msgout
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.980] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.980] [trace] (ID 6) - Command phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.981] [trace] (ID 6) - Controller is executing ReadToc, CDB $43000100000000000c40
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.981] [debug] (ID:LUN 6:0) - Device is executing ReadToc ($43)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.981] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.981] [trace] (ID 6) - Data In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.981] [trace] (ID 6) - Sending data, offset: 0, length: 12
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.981] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.981] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.981] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.982] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.982] [trace] (ID 6) - Message In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.982] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.982] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.982] [trace] (ID 6) - Bus Free phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.983] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.983] [trace] (ID 6) - Selection phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.983] [trace] (ID 6) - Selection completed
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.983] [trace] (ID 6) - Message Out phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.983] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.983] [trace] (ID 6) - Phase: msgout
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.983] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.983] [trace] (ID 6) - Command phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.984] [trace] (ID 6) - Controller is executing ReadToc, CDB $43000100000000000c40
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.984] [debug] (ID:LUN 6:0) - Device is executing ReadToc ($43)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.984] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.984] [trace] (ID 6) - Data In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.984] [trace] (ID 6) - Sending data, offset: 0, length: 12
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.984] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.984] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.984] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.985] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.985] [trace] (ID 6) - Message In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.985] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.985] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.985] [trace] (ID 6) - Bus Free phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.986] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.986] [trace] (ID 6) - Selection phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.986] [trace] (ID 6) - Selection completed
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.986] [trace] (ID 6) - Message Out phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.986] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.986] [trace] (ID 6) - Phase: msgout
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.986] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.986] [trace] (ID 6) - Command phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.987] [trace] (ID 6) - Controller is executing Read10, CDB $28000000010000000100
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.987] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.987] [trace] (ID:LUN 6:0) - READ/WRITE/VERIFY/SEEK, start block: $00000100, blocks: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.987] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.987] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.987] [trace] (ID:LUN 6:0) - Length is 2048
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.987] [trace] (ID 6) - Data In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.987] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.996] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.996] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.996] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.996] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.996] [trace] (ID 6) - Message In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.996] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.997] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.997] [trace] (ID 6) - Bus Free phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.998] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.998] [trace] (ID 6) - Selection phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.998] [trace] (ID 6) - Selection completed
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.998] [trace] (ID 6) - Message Out phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.998] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.998] [trace] (ID 6) - Phase: msgout
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.998] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.998] [trace] (ID 6) - Command phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.998] [trace] (ID 6) - Controller is executing ReadToc, CDB $43000100000000000c40
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.998] [debug] (ID:LUN 6:0) - Device is executing ReadToc ($43)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.999] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.999] [trace] (ID 6) - Data In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.999] [trace] (ID 6) - Sending data, offset: 0, length: 12
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.999] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.999] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.999] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.999] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:32.999] [trace] (ID 6) - Message In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.000] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.000] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.000] [trace] (ID 6) - Bus Free phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.001] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.001] [trace] (ID 6) - Selection phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.001] [trace] (ID 6) - Selection completed
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.001] [trace] (ID 6) - Message Out phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.001] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.001] [trace] (ID 6) - Phase: msgout
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.001] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.001] [trace] (ID 6) - Command phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.001] [trace] (ID 6) - Controller is executing Read10, CDB $28000000001000000100
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.001] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.002] [trace] (ID:LUN 6:0) - READ/WRITE/VERIFY/SEEK, start block: $00000010, blocks: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.002] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.002] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.002] [trace] (ID:LUN 6:0) - Length is 2048
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.002] [trace] (ID 6) - Data In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.002] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.011] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.011] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.011] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.011] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.011] [trace] (ID 6) - Message In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.012] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.012] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.012] [trace] (ID 6) - Bus Free phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.013] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.013] [trace] (ID 6) - Selection phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.013] [trace] (ID 6) - Selection completed
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.013] [trace] (ID 6) - Message Out phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.013] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.013] [trace] (ID 6) - Phase: msgout
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.013] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.013] [trace] (ID 6) - Command phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.013] [trace] (ID 6) - Controller is executing Read10, CDB $28000000001000000300
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.013] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.014] [trace] (ID:LUN 6:0) - READ/WRITE/VERIFY/SEEK, start block: $00000010, blocks: 3
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.014] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.014] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.014] [trace] (ID:LUN 6:0) - Length is 2048
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.014] [trace] (ID 6) - Data In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.014] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.022] [trace] (ID 6) - Command: $28
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.023] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.023] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.023] [trace] (ID 6) - Processing after data collection
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.023] [trace] (ID 6) - Continuing to send
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.023] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.031] [trace] (ID 6) - Command: $28
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.031] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.031] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.031] [trace] (ID 6) - Processing after data collection
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.031] [trace] (ID 6) - Continuing to send
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.031] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.040] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.040] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.040] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.041] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.041] [trace] (ID 6) - Message In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.041] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.041] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.041] [trace] (ID 6) - Bus Free phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.042] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.042] [trace] (ID 6) - Selection phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.042] [trace] (ID 6) - Selection completed
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.042] [trace] (ID 6) - Message Out phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.042] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.042] [trace] (ID 6) - Phase: msgout
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.042] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.042] [trace] (ID 6) - Command phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.043] [trace] (ID 6) - Controller is executing Read10, CDB $28000000002a00000100
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.043] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.043] [trace] (ID:LUN 6:0) - READ/WRITE/VERIFY/SEEK, start block: $0000002a, blocks: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.043] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.043] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.043] [trace] (ID:LUN 6:0) - Length is 2048
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.043] [trace] (ID 6) - Data In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.043] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.049] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.049] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.049] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.049] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.049] [trace] (ID 6) - Message In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.049] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.050] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.050] [trace] (ID 6) - Bus Free phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.056] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.056] [trace] (ID 6) - Selection phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.056] [trace] (ID 6) - Selection completed
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.056] [trace] (ID 6) - Message Out phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.056] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.056] [trace] (ID 6) - Phase: msgout
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.057] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.057] [trace] (ID 6) - Command phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.057] [trace] (ID 6) - Controller is executing Read10, CDB $28000000002a00000100
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.057] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.057] [trace] (ID:LUN 6:0) - READ/WRITE/VERIFY/SEEK, start block: $0000002a, blocks: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.057] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.057] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.057] [trace] (ID:LUN 6:0) - Length is 2048
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.057] [trace] (ID 6) - Data In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.057] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.063] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.063] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.063] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.064] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.064] [trace] (ID 6) - Message In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.064] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.064] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.064] [trace] (ID 6) - Bus Free phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.067] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.067] [trace] (ID 6) - Selection phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.067] [trace] (ID 6) - Selection completed
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.067] [trace] (ID 6) - Message Out phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.067] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.067] [trace] (ID 6) - Phase: msgout
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.067] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.067] [trace] (ID 6) - Command phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.067] [trace] (ID 6) - Controller is executing Read10, CDB $28000000003200000100
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.067] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.067] [trace] (ID:LUN 6:0) - READ/WRITE/VERIFY/SEEK, start block: $00000032, blocks: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.067] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.067] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.067] [trace] (ID:LUN 6:0) - Length is 2048
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.068] [trace] (ID 6) - Data In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.068] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.074] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.074] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.074] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.074] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.074] [trace] (ID 6) - Message In phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.074] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.074] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.074] [trace] (ID 6) - Bus Free phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.101] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.101] [trace] (ID 6) - Selection phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.102] [trace] (ID 6) - Selection completed
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.102] [trace] (ID 6) - Message Out phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.102] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.102] [trace] (ID 6) - Phase: msgout
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.102] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.102] [trace] (ID 6) - Command phase
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.102] [trace] (ID 6) - Controller is executing Read10, CDB $28000000002b00000100
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.102] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:25:33 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.102] [trace] (ID:LUN 6:0) - READ/WRITE/VERIFY/SEEK, start block: $0000002b, blocks: 1
Jul 22 16:25:34 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.102] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:34 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.102] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:34 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.102] [trace] (ID:LUN 6:0) - Length is 2048
Jul 22 16:25:34 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.102] [trace] (ID 6) - Data In phase
Jul 22 16:25:34 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.102] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:25:34 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.108] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:25:34 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.109] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:25:34 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.109] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:34 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.109] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:25:34 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.109] [trace] (ID 6) - Message In phase
Jul 22 16:25:34 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.109] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:34 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.109] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:25:34 raspberrypi PISCSI[1008]: [2024-07-22 16:25:33.109] [trace] (ID 6) - Bus Free phase
Jul 22 16:25:35 raspberrypi PISCSI[1008]: [2024-07-22 16:25:35.298] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:25:35 raspberrypi PISCSI[1008]: [2024-07-22 16:25:35.299] [trace] (ID 6) - Selection phase
Jul 22 16:25:35 raspberrypi PISCSI[1008]: [2024-07-22 16:25:35.299] [trace] (ID 6) - Selection completed
Jul 22 16:25:35 raspberrypi PISCSI[1008]: [2024-07-22 16:25:35.299] [trace] (ID 6) - Message Out phase
Jul 22 16:25:35 raspberrypi PISCSI[1008]: [2024-07-22 16:25:35.299] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:25:35 raspberrypi PISCSI[1008]: [2024-07-22 16:25:35.299] [trace] (ID 6) - Phase: msgout
Jul 22 16:25:35 raspberrypi PISCSI[1008]: [2024-07-22 16:25:35.299] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:25:35 raspberrypi PISCSI[1008]: [2024-07-22 16:25:35.299] [trace] (ID 6) - Command phase
Jul 22 16:25:35 raspberrypi PISCSI[1008]: [2024-07-22 16:25:35.299] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $000000000000
Jul 22 16:25:35 raspberrypi PISCSI[1008]: [2024-07-22 16:25:35.299] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:25:35 raspberrypi PISCSI[1008]: [2024-07-22 16:25:35.299] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:35 raspberrypi PISCSI[1008]: [2024-07-22 16:25:35.299] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:25:35 raspberrypi PISCSI[1008]: [2024-07-22 16:25:35.300] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:35 raspberrypi PISCSI[1008]: [2024-07-22 16:25:35.300] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:25:35 raspberrypi PISCSI[1008]: [2024-07-22 16:25:35.300] [trace] (ID 6) - Message In phase
Jul 22 16:25:35 raspberrypi PISCSI[1008]: [2024-07-22 16:25:35.300] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:35 raspberrypi PISCSI[1008]: [2024-07-22 16:25:35.300] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:25:35 raspberrypi PISCSI[1008]: [2024-07-22 16:25:35.300] [trace] (ID 6) - Bus Free phase
Jul 22 16:25:38 raspberrypi PISCSI[1008]: [2024-07-22 16:25:38.318] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:25:38 raspberrypi PISCSI[1008]: [2024-07-22 16:25:38.318] [trace] (ID 6) - Selection phase
Jul 22 16:25:38 raspberrypi PISCSI[1008]: [2024-07-22 16:25:38.318] [trace] (ID 6) - Selection completed
Jul 22 16:25:38 raspberrypi PISCSI[1008]: [2024-07-22 16:25:38.318] [trace] (ID 6) - Message Out phase
Jul 22 16:25:38 raspberrypi PISCSI[1008]: [2024-07-22 16:25:38.318] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:25:38 raspberrypi PISCSI[1008]: [2024-07-22 16:25:38.318] [trace] (ID 6) - Phase: msgout
Jul 22 16:25:38 raspberrypi PISCSI[1008]: [2024-07-22 16:25:38.318] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:25:38 raspberrypi PISCSI[1008]: [2024-07-22 16:25:38.318] [trace] (ID 6) - Command phase
Jul 22 16:25:38 raspberrypi PISCSI[1008]: [2024-07-22 16:25:38.319] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $000000000000
Jul 22 16:25:38 raspberrypi PISCSI[1008]: [2024-07-22 16:25:38.319] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:25:38 raspberrypi PISCSI[1008]: [2024-07-22 16:25:38.319] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:25:38 raspberrypi PISCSI[1008]: [2024-07-22 16:25:38.319] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:25:38 raspberrypi PISCSI[1008]: [2024-07-22 16:25:38.319] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:38 raspberrypi PISCSI[1008]: [2024-07-22 16:25:38.319] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:25:38 raspberrypi PISCSI[1008]: [2024-07-22 16:25:38.319] [trace] (ID 6) - Message In phase
Jul 22 16:25:38 raspberrypi PISCSI[1008]: [2024-07-22 16:25:38.319] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:25:38 raspberrypi PISCSI[1008]: [2024-07-22 16:25:38.320] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:25:38 raspberrypi PISCSI[1008]: [2024-07-22 16:25:38.320] [trace] (ID 6) - Bus Free phase
^C
uweseimet commented 4 months ago

Thank you. Looks as if SCSI2Pi stops early when reading the TOC.

Any chance that you upload the full ISO image somewhere? If needed I can probably provide a temporary sftp location for this purpose.

From the logs I can see that SCSI2Pi does not return the full set of TOC data. I cannot reproduce this problem with the ISO image I use for testing, so being able to use your image for testing would be helpful.

SavourySnaX commented 4 months ago

Let me see if i can find a cd that I can share - (amigaos3.2 is paid and non distributable)

EasyNet (2010-06-10)(AmigaKit).zip This image exhibits the same problem. (perhaps its something during boot - the amiga probes the devices during early config) - I`ll attach full logs of upto mounting in a second.

SavourySnaX commented 4 months ago

s2p

[2024-07-22 16:34:21.977] [info] Set log level to 'trace'
[2024-07-22 16:34:22.024] [trace] Executing CHECK_AUTHENTICATION command
[2024-07-22 16:34:22.024] [trace] Received CHECK_AUTHENTICATION command
[2024-07-22 16:34:22.036] [trace] Executing SERVER_INFO command
[2024-07-22 16:34:22.153] [trace] Executing DEVICES_INFO command
[2024-07-22 16:34:22.166] [trace] Executing DEFAULT_IMAGE_FILES_INFO command
[2024-07-22 16:34:22.189] [trace] Executing DEVICE_TYPES_INFO command
[2024-07-22 16:34:22.220] [trace] Executing DEFAULT_IMAGE_FILES_INFO command
[2024-07-22 16:34:22.242] [trace] Executing SERVER_INFO command
[2024-07-22 16:34:22.388] [trace] Executing NETWORK_INTERFACES_INFO command
[2024-07-22 16:34:22.438] [trace] Executing DEVICE_TYPES_INFO command
[2024-07-22 16:34:22.466] [trace] Executing DEVICE_TYPES_INFO command
[2024-07-22 16:34:22.492] [trace] Executing DEVICE_TYPES_INFO command
[2024-07-22 16:34:22.517] [trace] Executing DEVICE_TYPES_INFO command
[2024-07-22 16:34:22.545] [trace] Executing SERVER_INFO command
[2024-07-22 16:34:23.172] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:23.173] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:23.173] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:34:23.173] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:34:23.173] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:34:23.173] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:23.173] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:34:23.173] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:34:23.173] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:34:23.173] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:23.173] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.173] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:23.173] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:23.174] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.174] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:23.175] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:23.176] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:23.178] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:34:23.178] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:34:23.179] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:34:23.180] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:23.180] [debug] (ID 6) - Controller is executing READ CAPACITY(10), CDB $25:00:00:00:00:00:00:00:00:00
[2024-07-22 16:34:23.181] [debug] (ID:LUN 6:0) - Device is executing READ CAPACITY(10) ($25)
[2024-07-22 16:34:23.181] [trace] (ID 6) - DATA IN phase
[2024-07-22 16:34:23.181] [trace] (ID 6) - Sending 8 byte(s)
[2024-07-22 16:34:23.182] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.183] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:34:23.193] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:23.194] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.195] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:23.195] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:23.195] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.196] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:23.197] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:23.198] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:23.198] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:34:23.198] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:34:23.200] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:34:23.200] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:23.200] [debug] (ID 6) - Controller is executing MODE SENSE(6), CDB $1a:00:00:00:0c:00
[2024-07-22 16:34:23.201] [debug] (ID:LUN 6:0) - Device is executing MODE SENSE(6) ($1a)
[2024-07-22 16:34:23.202] [debug] (ID 6) - ILLEGAL REQUEST (Sense Key $05), INVALID FIELD IN CDB (ASC $24), ASCQ $00
[2024-07-22 16:34:23.203] [trace] (ID 6) - Status phase, status is CHECK CONDITION (status code $02)
[2024-07-22 16:34:23.204] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:23.204] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.205] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:23.206] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:23.206] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.207] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:23.208] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:23.208] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:23.208] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:34:23.208] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:34:23.208] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:34:23.209] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:23.209] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:34:23.209] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:34:23.210] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:34:23.210] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:23.211] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.211] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:23.212] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:23.213] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.214] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:23.215] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:23.216] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:23.216] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:34:23.216] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:34:23.217] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:34:23.217] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:23.217] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:34:23.218] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:34:23.218] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:34:23.219] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:23.220] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.221] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:23.221] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:23.223] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.223] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:23.224] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:23.224] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:23.224] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:34:23.225] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:34:23.225] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:34:23.225] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:23.226] [debug] (ID 6) - Controller is executing READ TOC, CDB $43:02:02:00:00:00:00:04:50:00
[2024-07-22 16:34:23.226] [debug] (ID:LUN 6:0) - Device is executing READ TOC ($43)
[2024-07-22 16:34:23.227] [trace] (ID 6) - DATA IN phase
[2024-07-22 16:34:23.227] [trace] (ID 6) - Sending 12 byte(s)
[2024-07-22 16:34:23.229] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.231] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:34:23.232] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:23.232] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.233] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:23.234] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:23.235] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.235] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:23.236] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:23.238] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:23.238] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:34:23.238] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:34:23.238] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:34:23.239] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:23.241] [debug] (ID 6) - Controller is executing READ TOC, CDB $43:00:00:00:00:00:00:03:24:00
[2024-07-22 16:34:23.242] [debug] (ID:LUN 6:0) - Device is executing READ TOC ($43)
[2024-07-22 16:34:23.242] [trace] (ID 6) - DATA IN phase
[2024-07-22 16:34:23.242] [trace] (ID 6) - Sending 12 byte(s)
[2024-07-22 16:34:23.244] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.245] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:34:23.246] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:23.246] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.247] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:23.247] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:23.248] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.250] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:23.253] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:23.254] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:23.254] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:34:23.254] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:34:23.254] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:34:23.255] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:23.255] [debug] (ID 6) - Controller is executing READ TOC, CDB $43:00:05:00:00:00:00:07:1e:00
[2024-07-22 16:34:23.256] [debug] (ID:LUN 6:0) - Device is executing READ TOC ($43)
[2024-07-22 16:34:23.257] [trace] (ID 6) - DATA IN phase
[2024-07-22 16:34:23.257] [trace] (ID 6) - Sending 12 byte(s)
[2024-07-22 16:34:23.257] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.259] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:34:23.259] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:23.260] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.260] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:23.260] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:23.261] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:23.263] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:23.637] [trace] Executing CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.637] [trace] Received CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.727] [trace] Executing CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.727] [trace] Received CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.750] [trace] Executing CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.750] [trace] Received CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.777] [trace] Executing CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.777] [trace] Received CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.809] [trace] Executing CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.809] [trace] Received CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.838] [trace] Executing CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.838] [trace] Received CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.867] [trace] Executing CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.868] [trace] Received CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.897] [trace] Executing CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.897] [trace] Received CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.923] [trace] Executing CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.923] [trace] Received CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.949] [trace] Executing CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.949] [trace] Received CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.978] [trace] Executing CHECK_AUTHENTICATION command
[2024-07-22 16:34:23.978] [trace] Received CHECK_AUTHENTICATION command
[2024-07-22 16:34:24.004] [trace] Executing CHECK_AUTHENTICATION command
[2024-07-22 16:34:24.004] [trace] Received CHECK_AUTHENTICATION command
[2024-07-22 16:34:24.030] [trace] Executing CHECK_AUTHENTICATION command
[2024-07-22 16:34:24.030] [trace] Received CHECK_AUTHENTICATION command
[2024-07-22 16:34:26.212] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:26.212] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:26.212] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:34:26.212] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:34:26.212] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:34:26.212] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:26.213] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:34:26.213] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:34:26.213] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:34:26.213] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:26.213] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:26.213] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:26.213] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:26.213] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:26.213] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:29.232] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:29.232] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:29.232] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:34:29.232] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:34:29.232] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:34:29.232] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:29.232] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:34:29.233] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:34:29.233] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:34:29.233] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:29.233] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:29.233] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:29.233] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:29.233] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:29.233] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:32.252] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:32.252] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:32.252] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:34:32.252] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:34:32.252] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:34:32.252] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:32.253] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:34:32.253] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:34:32.253] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:34:32.253] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:32.253] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:32.253] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:32.253] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:32.253] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:32.253] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:35.272] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:35.272] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:35.272] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:34:35.272] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:34:35.273] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:34:35.273] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:35.273] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:34:35.273] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:34:35.273] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:34:35.273] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:35.273] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:35.273] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:35.273] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:35.274] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:35.274] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:38.293] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:38.293] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:38.293] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:34:38.293] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:34:38.293] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:34:38.293] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:38.293] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:34:38.293] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:34:38.294] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:34:38.294] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:38.294] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:38.294] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:38.294] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:38.294] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:38.294] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:53.394] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:53.395] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:53.395] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:53.395] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:34:53.395] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:34:53.395] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:34:53.395] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:53.395] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:53.395] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:53.395] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:53.395] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:53.396] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:53.397] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:53.398] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:53.399] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:53.399] [debug] (ID 6) - Controller is executing INQUIRY, CDB $12:00:00:00:fe:00
[2024-07-22 16:34:53.400] [debug] (ID:LUN 6:0) - Device is executing INQUIRY ($12)
[2024-07-22 16:34:53.400] [trace] (ID 6) - DATA IN phase
[2024-07-22 16:34:53.400] [trace] (ID 6) - Sending 36 byte(s)
[2024-07-22 16:34:53.401] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:53.402] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:34:53.402] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:53.403] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:53.405] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:53.406] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:53.406] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:53.408] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:53.409] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:53.409] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:53.410] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:53.410] [debug] (ID 6) - Controller is executing START STOP UNIT/STOP PRINT, CDB $1b:00:00:00:01:00
[2024-07-22 16:34:53.410] [debug] (ID:LUN 6:0) - Device is executing START STOP UNIT/STOP PRINT ($1b)
[2024-07-22 16:34:53.410] [trace] (ID:LUN 6:0) - Starting unit
[2024-07-22 16:34:53.411] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:34:53.411] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:53.412] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:53.413] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:53.413] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:53.414] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:53.415] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:53.417] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:53.417] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:53.417] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:53.417] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:34:53.418] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:34:53.418] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:34:53.418] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:53.420] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:53.421] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:53.421] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:53.422] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:53.423] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:53.424] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:53.424] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:53.425] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:53.425] [debug] (ID 6) - Controller is executing READ CAPACITY(10), CDB $25:00:00:00:00:00:00:00:00:00
[2024-07-22 16:34:53.425] [debug] (ID:LUN 6:0) - Device is executing READ CAPACITY(10) ($25)
[2024-07-22 16:34:53.426] [trace] (ID 6) - DATA IN phase
[2024-07-22 16:34:53.426] [trace] (ID 6) - Sending 8 byte(s)
[2024-07-22 16:34:53.427] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:53.428] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:34:53.428] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:53.429] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:53.430] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:53.431] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:53.432] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:53.432] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:53.433] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:53.433] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:53.433] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:53.434] [debug] (ID 6) - Controller is executing MODE SENSE(6), CDB $1a:00:00:00:0c:00
[2024-07-22 16:34:53.434] [debug] (ID:LUN 6:0) - Device is executing MODE SENSE(6) ($1a)
[2024-07-22 16:34:53.435] [debug] (ID 6) - ILLEGAL REQUEST (Sense Key $05), INVALID FIELD IN CDB (ASC $24), ASCQ $00
[2024-07-22 16:34:53.437] [trace] (ID 6) - Status phase, status is CHECK CONDITION (status code $02)
[2024-07-22 16:34:53.437] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:53.438] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:53.440] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:53.440] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:53.440] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:53.441] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:53.444] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:53.445] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:53.445] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:53.445] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:20:00:00:00:00
[2024-07-22 16:34:53.445] [debug] (ID 6) - ILLEGAL REQUEST (Sense Key $05), LOGICAL UNIT NOT SUPPORTED (ASC $25), ASCQ $00
[2024-07-22 16:34:53.445] [trace] (ID 6) - Status phase, status is CHECK CONDITION (status code $02)
[2024-07-22 16:34:53.445] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:53.446] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:53.447] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:53.447] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:53.447] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:53.448] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:53.450] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:53.450] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:53.450] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:53.451] [debug] (ID 6) - Controller is executing INQUIRY, CDB $12:20:00:00:fe:00
[2024-07-22 16:34:53.451] [debug] (ID:LUN 6:0) - Device is executing INQUIRY ($12)
[2024-07-22 16:34:53.452] [trace] (ID 6) - DATA IN phase
[2024-07-22 16:34:53.452] [trace] (ID 6) - Sending 36 byte(s)
[2024-07-22 16:34:53.452] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:53.454] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:34:53.454] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:53.455] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:53.457] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:53.457] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:53.457] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:53.458] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:34:57.301] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:34:57.301] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:34:57.301] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:34:57.302] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:34:57.303] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:34:57.303] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:34:57.303] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:34:57.304] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:34:57.304] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:34:57.304] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:57.305] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:57.307] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:34:57.307] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:34:57.308] [trace] (ID 6) - All data transferred
[2024-07-22 16:34:57.310] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:02.342] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:02.342] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:02.342] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:02.342] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:02.342] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:02.342] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:02.342] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:02.343] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:02.343] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:02.343] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:02.343] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:02.343] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:02.343] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:02.343] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:02.343] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:05.475] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:05.475] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:05.476] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:05.476] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:05.476] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:05.476] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:05.476] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:05.476] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:05.476] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:05.476] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:05.476] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:05.476] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:05.476] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:05.477] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:05.477] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:08.626] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:08.626] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:08.626] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:08.626] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:08.626] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:08.626] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:08.626] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:08.626] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:08.626] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:08.626] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:08.627] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:08.627] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:08.627] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:08.627] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:08.627] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:11.645] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:11.645] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:11.645] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:11.645] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:11.645] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:11.645] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:11.645] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:11.646] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:11.646] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:11.646] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:11.646] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:11.646] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:11.646] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:11.646] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:11.646] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:14.665] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:14.665] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:14.665] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:14.665] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:14.665] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:14.665] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:14.665] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:14.665] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:14.665] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:14.666] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:14.666] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:14.666] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:14.666] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:14.666] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:14.666] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:17.916] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:17.916] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:17.916] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:17.916] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:17.916] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:17.916] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:17.916] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:17.916] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:17.916] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:17.916] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:17.917] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:17.917] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:17.917] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:17.917] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:17.917] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:22.685] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:22.685] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:22.685] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:22.685] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:22.685] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:22.685] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:22.685] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:22.685] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:22.685] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:22.685] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:22.686] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:22.686] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:22.686] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:22.686] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:22.686] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:25.705] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:25.705] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:25.705] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:25.705] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:25.705] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:25.705] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:25.705] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:25.705] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:25.705] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:25.706] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:25.706] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:25.706] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:25.706] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:25.706] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:25.706] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:28.725] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:28.725] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:28.725] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:28.725] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:28.726] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:28.726] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:28.726] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:28.726] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:28.726] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:28.726] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:28.726] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:28.726] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:28.726] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:28.727] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:28.727] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:31.745] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:31.745] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:31.745] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:31.745] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:31.745] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:31.745] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:31.745] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:31.745] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:31.745] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:31.746] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:31.746] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:31.746] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:31.746] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:31.746] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:31.746] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:34.765] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:34.765] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:34.765] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:34.765] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:34.765] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:34.765] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:34.765] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:34.765] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:34.765] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:34.765] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:34.766] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:34.766] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:34.766] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:34.766] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:34.766] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:37.785] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:37.785] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:37.785] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:37.785] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:37.785] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:37.785] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:37.785] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:37.785] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:37.785] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:37.786] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:37.786] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:37.786] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:37.786] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:37.786] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:37.786] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:40.805] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:40.805] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:40.805] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:40.805] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:40.805] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:40.805] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:40.805] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:40.805] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:40.805] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:40.805] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:40.806] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:40.806] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:40.806] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:40.806] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:40.806] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:43.825] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:43.825] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:43.825] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:43.825] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:43.825] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:43.825] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:43.825] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:43.825] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:43.825] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:43.825] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:43.826] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:43.826] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:43.826] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:43.826] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:43.826] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:46.845] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:46.847] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:46.847] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:46.848] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:46.848] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:46.849] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:46.849] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:46.851] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:46.851] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:46.852] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:46.854] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:46.854] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:46.856] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:46.856] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:46.857] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:49.865] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:49.865] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:49.865] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:49.865] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:49.865] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:49.865] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:49.865] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:49.865] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:49.865] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:49.866] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:49.866] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:49.866] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:49.866] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:49.866] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:49.866] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:52.886] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:52.886] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:52.886] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:52.886] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:52.886] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:52.886] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:52.886] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:52.886] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:52.887] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:52.887] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:52.887] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:52.887] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:52.887] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:52.887] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:52.887] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:55.313] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:55.313] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:55.313] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:55.313] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:55.313] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:55.313] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:55.314] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:55.314] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:55.314] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:55.314] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:55.314] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:55.314] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:55.314] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:55.314] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:55.314] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:55.316] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:55.317] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:55.317] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:55.318] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:55.318] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:55.321] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:55.323] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:55.324] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:55.324] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:55.324] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:55.325] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:55.326] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:55.327] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:55.329] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:55.329] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:55.331] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:55.333] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:55.333] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:55.333] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:55.333] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:55.333] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:55.334] [debug] (ID 6) - Controller is executing READ TOC, CDB $43:02:02:00:00:00:00:04:50:00
[2024-07-22 16:35:55.335] [debug] (ID:LUN 6:0) - Device is executing READ TOC ($43)
[2024-07-22 16:35:55.336] [trace] (ID 6) - DATA IN phase
[2024-07-22 16:35:55.336] [trace] (ID 6) - Sending 12 byte(s)
[2024-07-22 16:35:55.337] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:55.339] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:55.339] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:55.341] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:55.341] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:55.341] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:55.342] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:55.343] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:55.345] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:55.345] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:55.346] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:55.346] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:55.346] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:55.347] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:55.349] [debug] (ID 6) - Controller is executing READ TOC, CDB $43:00:00:00:00:00:00:03:24:00
[2024-07-22 16:35:55.350] [debug] (ID:LUN 6:0) - Device is executing READ TOC ($43)
[2024-07-22 16:35:55.351] [trace] (ID 6) - DATA IN phase
[2024-07-22 16:35:55.351] [trace] (ID 6) - Sending 12 byte(s)
[2024-07-22 16:35:55.351] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:55.353] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:55.353] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:55.355] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:55.355] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:55.357] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:55.357] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:55.358] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:55.361] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:55.361] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:55.361] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:55.361] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:55.362] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:55.362] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:55.364] [debug] (ID 6) - Controller is executing READ TOC, CDB $43:00:05:00:00:00:00:07:1e:00
[2024-07-22 16:35:55.365] [debug] (ID:LUN 6:0) - Device is executing READ TOC ($43)
[2024-07-22 16:35:55.366] [trace] (ID 6) - DATA IN phase
[2024-07-22 16:35:55.366] [trace] (ID 6) - Sending 12 byte(s)
[2024-07-22 16:35:55.366] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:55.368] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:55.368] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:55.370] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:55.370] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:55.372] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:55.372] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:55.374] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:55.905] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:55.905] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:55.906] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:55.906] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:55.906] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:55.906] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:55.906] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:55.907] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:55.907] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:55.908] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:55.908] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:55.908] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:55.909] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:55.909] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:55.910] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:35:58.925] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:35:58.925] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:35:58.925] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:35:58.926] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:35:58.926] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:35:58.926] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:35:58.927] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:35:58.928] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:35:58.928] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:35:58.928] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:58.929] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:58.930] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:35:58.930] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:35:58.933] [trace] (ID 6) - All data transferred
[2024-07-22 16:35:58.933] [trace] (ID 6) - BUS FREE phase
[2024-07-22 16:36:01.945] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
[2024-07-22 16:36:01.945] [trace] (ID 6) - SELECTION phase
[2024-07-22 16:36:01.945] [trace] (ID 6) - MESSAGE OUT phase
[2024-07-22 16:36:01.946] [trace] (ID 6) - Receiving 1 byte(s)
[2024-07-22 16:36:01.946] [trace] (ID 6) - Received IDENTIFY message for LUN 0
[2024-07-22 16:36:01.946] [trace] (ID 6) - COMMAND phase
[2024-07-22 16:36:01.946] [debug] (ID 6) - Controller is executing TEST UNIT READY, CDB $00:00:00:00:00:00
[2024-07-22 16:36:01.946] [debug] (ID:LUN 6:0) - Device is executing TEST UNIT READY ($00)
[2024-07-22 16:36:01.947] [trace] (ID 6) - Status phase, status is GOOD (status code $00)
[2024-07-22 16:36:01.947] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:36:01.948] [trace] (ID 6) - All data transferred
[2024-07-22 16:36:01.948] [trace] (ID 6) - MESSAGE IN phase
[2024-07-22 16:36:01.948] [trace] (ID 6) - Sending 1 byte(s)
[2024-07-22 16:36:01.949] [trace] (ID 6) - All data transferred
[2024-07-22 16:36:01.949] [trace] (ID 6) - BUS FREE phase
^C[2024-07-22 16:36:02.176] [info] Detached all devices
SavourySnaX commented 4 months ago

piscsi

Jul 22 16:41:15 raspberrypi PISCSI[1245]: [2024-07-22 16:41:15.766] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $000000000000
Jul 22 16:41:15 raspberrypi PISCSI[1245]: [2024-07-22 16:41:15.766] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:41:15 raspberrypi PISCSI[1245]: [2024-07-22 16:41:15.766] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:41:15 raspberrypi PISCSI[1245]: [2024-07-22 16:41:15.766] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:41:15 raspberrypi PISCSI[1245]: [2024-07-22 16:41:15.766] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:15 raspberrypi PISCSI[1245]: [2024-07-22 16:41:15.766] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:41:15 raspberrypi PISCSI[1245]: [2024-07-22 16:41:15.767] [trace] (ID 6) - Message In phase
Jul 22 16:41:15 raspberrypi PISCSI[1245]: [2024-07-22 16:41:15.767] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:15 raspberrypi PISCSI[1245]: [2024-07-22 16:41:15.767] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:41:15 raspberrypi PISCSI[1245]: [2024-07-22 16:41:15.767] [trace] (ID 6) - Bus Free phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.577] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.577] [trace] (ID 6) - Selection phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.577] [trace] (ID 6) - Selection completed
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.577] [trace] (ID 6) - Command phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.578] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $000000000000
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.578] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.578] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.578] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.578] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.578] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.578] [trace] (ID 6) - Message In phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.578] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.579] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.579] [trace] (ID 6) - Bus Free phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.579] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.580] [trace] (ID 6) - Selection phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.580] [trace] (ID 6) - Selection completed
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.580] [trace] (ID 6) - Command phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.580] [trace] (ID 6) - Controller is executing Inquiry, CDB $12000000fe00
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.580] [debug] (ID:LUN 6:0) - Device is executing Inquiry ($12)
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.580] [trace] (ID 6) - Data In phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.580] [trace] (ID 6) - Sending data, offset: 0, length: 36
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.581] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.581] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.581] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.581] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.581] [trace] (ID 6) - Message In phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.581] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.582] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.582] [trace] (ID 6) - Bus Free phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.583] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.583] [trace] (ID 6) - Selection phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.583] [trace] (ID 6) - Selection completed
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.583] [trace] (ID 6) - Command phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.583] [trace] (ID 6) - Controller is executing StartStop, CDB $1b0000000100
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.583] [debug] (ID:LUN 6:0) - Device is executing StartStop ($1b)
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.583] [trace] (ID:LUN 6:0) - Starting unit
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.584] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.584] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.584] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.584] [trace] (ID 6) - Message In phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.584] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.584] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.584] [trace] (ID 6) - Bus Free phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.585] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.585] [trace] (ID 6) - Selection phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.585] [trace] (ID 6) - Selection completed
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.585] [trace] (ID 6) - Command phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.586] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $000000000000
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.586] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.586] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.586] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.586] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.586] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.586] [trace] (ID 6) - Message In phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.586] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.587] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.587] [trace] (ID 6) - Bus Free phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.588] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.588] [trace] (ID 6) - Selection phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.588] [trace] (ID 6) - Selection completed
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.588] [trace] (ID 6) - Command phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.588] [trace] (ID 6) - Controller is executing ReadCapacity10, CDB $25000000000000000000
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.588] [debug] (ID:LUN 6:0) - Device is executing ReadCapacity10 ($25)
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.588] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.588] [trace] (ID 6) - Data In phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.588] [trace] (ID 6) - Sending data, offset: 0, length: 8
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.589] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.589] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.589] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.589] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.589] [trace] (ID 6) - Message In phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.589] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.590] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.590] [trace] (ID 6) - Bus Free phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.590] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.591] [trace] (ID 6) - Selection phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.591] [trace] (ID 6) - Selection completed
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.591] [trace] (ID 6) - Command phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.591] [trace] (ID 6) - Controller is executing ModeSense6, CDB $1a0000000c00
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.591] [debug] (ID:LUN 6:0) - Device is executing ModeSense6 ($1a)
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.591] [trace] (ID:LUN 6:0) - Requesting mode page $00
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.591] [trace] (ID:LUN 6:0) - Requesting mode page $00Unsupported mode page $0
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.591] [debug] (ID 6) - Error status: Sense Key $05, ASC $24
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.592] [trace] (ID 6) - Status phase, status is $02
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.592] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.592] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.592] [trace] (ID 6) - Message In phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.592] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.592] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.593] [trace] (ID 6) - Bus Free phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.595] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.595] [trace] (ID 6) - Selection phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.595] [trace] (ID 6) - Selection completed
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.595] [trace] (ID 6) - Command phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.595] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $002000000000
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.595] [trace] (ID 6) - Invalid LUN 1
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.595] [debug] (ID 6) - Error status: Sense Key $05, ASC $25
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.595] [trace] (ID 6) - Status phase, status is $02
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.595] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.596] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.596] [trace] (ID 6) - Message In phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.596] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.596] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.596] [trace] (ID 6) - Bus Free phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.597] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.597] [trace] (ID 6) - Selection phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.597] [trace] (ID 6) - Selection completed
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.597] [trace] (ID 6) - Command phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.597] [trace] (ID 6) - Controller is executing Inquiry, CDB $12200000fe00
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.597] [debug] (ID:LUN 6:0) - Device is executing Inquiry ($12)
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.598] [trace] (ID:LUN 6:0) - LUN is not available
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.598] [trace] (ID 6) - Data In phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.598] [trace] (ID 6) - Sending data, offset: 0, length: 36
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.598] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.598] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.598] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.599] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.599] [trace] (ID 6) - Message In phase
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.599] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.599] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:41:29 raspberrypi PISCSI[1245]: [2024-07-22 16:41:29.599] [trace] (ID 6) - Bus Free phase
Jul 22 16:41:33 raspberrypi PISCSI[1245]: [2024-07-22 16:41:33.444] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:41:33 raspberrypi PISCSI[1245]: [2024-07-22 16:41:33.444] [trace] (ID 6) - Selection phase
Jul 22 16:41:33 raspberrypi PISCSI[1245]: [2024-07-22 16:41:33.444] [trace] (ID 6) - Selection completed
Jul 22 16:41:33 raspberrypi PISCSI[1245]: [2024-07-22 16:41:33.444] [trace] (ID 6) - Message Out phase
Jul 22 16:41:33 raspberrypi PISCSI[1245]: [2024-07-22 16:41:33.444] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:41:33 raspberrypi PISCSI[1245]: [2024-07-22 16:41:33.444] [trace] (ID 6) - Phase: msgout
Jul 22 16:41:33 raspberrypi PISCSI[1245]: [2024-07-22 16:41:33.444] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:41:33 raspberrypi PISCSI[1245]: [2024-07-22 16:41:33.444] [trace] (ID 6) - Command phase
Jul 22 16:41:33 raspberrypi PISCSI[1245]: [2024-07-22 16:41:33.444] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $000000000000
Jul 22 16:41:33 raspberrypi PISCSI[1245]: [2024-07-22 16:41:33.444] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:41:33 raspberrypi PISCSI[1245]: [2024-07-22 16:41:33.445] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:41:33 raspberrypi PISCSI[1245]: [2024-07-22 16:41:33.445] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:41:33 raspberrypi PISCSI[1245]: [2024-07-22 16:41:33.445] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:33 raspberrypi PISCSI[1245]: [2024-07-22 16:41:33.445] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:41:33 raspberrypi PISCSI[1245]: [2024-07-22 16:41:33.445] [trace] (ID 6) - Message In phase
Jul 22 16:41:33 raspberrypi PISCSI[1245]: [2024-07-22 16:41:33.445] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:33 raspberrypi PISCSI[1245]: [2024-07-22 16:41:33.445] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:41:33 raspberrypi PISCSI[1245]: [2024-07-22 16:41:33.445] [trace] (ID 6) - Bus Free phase
Jul 22 16:41:38 raspberrypi PISCSI[1245]: [2024-07-22 16:41:38.488] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:41:38 raspberrypi PISCSI[1245]: [2024-07-22 16:41:38.489] [trace] (ID 6) - Selection phase
Jul 22 16:41:38 raspberrypi PISCSI[1245]: [2024-07-22 16:41:38.489] [trace] (ID 6) - Selection completed
Jul 22 16:41:38 raspberrypi PISCSI[1245]: [2024-07-22 16:41:38.489] [trace] (ID 6) - Message Out phase
Jul 22 16:41:38 raspberrypi PISCSI[1245]: [2024-07-22 16:41:38.489] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:41:38 raspberrypi PISCSI[1245]: [2024-07-22 16:41:38.489] [trace] (ID 6) - Phase: msgout
Jul 22 16:41:38 raspberrypi PISCSI[1245]: [2024-07-22 16:41:38.489] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:41:38 raspberrypi PISCSI[1245]: [2024-07-22 16:41:38.489] [trace] (ID 6) - Command phase
Jul 22 16:41:38 raspberrypi PISCSI[1245]: [2024-07-22 16:41:38.489] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $000000000000
Jul 22 16:41:38 raspberrypi PISCSI[1245]: [2024-07-22 16:41:38.489] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:41:38 raspberrypi PISCSI[1245]: [2024-07-22 16:41:38.489] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:41:38 raspberrypi PISCSI[1245]: [2024-07-22 16:41:38.489] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:41:38 raspberrypi PISCSI[1245]: [2024-07-22 16:41:38.490] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:38 raspberrypi PISCSI[1245]: [2024-07-22 16:41:38.490] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:41:38 raspberrypi PISCSI[1245]: [2024-07-22 16:41:38.490] [trace] (ID 6) - Message In phase
Jul 22 16:41:38 raspberrypi PISCSI[1245]: [2024-07-22 16:41:38.490] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:38 raspberrypi PISCSI[1245]: [2024-07-22 16:41:38.490] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:41:38 raspberrypi PISCSI[1245]: [2024-07-22 16:41:38.490] [trace] (ID 6) - Bus Free phase
Jul 22 16:41:41 raspberrypi PISCSI[1245]: [2024-07-22 16:41:41.618] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:41:41 raspberrypi PISCSI[1245]: [2024-07-22 16:41:41.618] [trace] (ID 6) - Selection phase
Jul 22 16:41:41 raspberrypi PISCSI[1245]: [2024-07-22 16:41:41.618] [trace] (ID 6) - Selection completed
Jul 22 16:41:41 raspberrypi PISCSI[1245]: [2024-07-22 16:41:41.618] [trace] (ID 6) - Message Out phase
Jul 22 16:41:41 raspberrypi PISCSI[1245]: [2024-07-22 16:41:41.618] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:41:41 raspberrypi PISCSI[1245]: [2024-07-22 16:41:41.619] [trace] (ID 6) - Phase: msgout
Jul 22 16:41:41 raspberrypi PISCSI[1245]: [2024-07-22 16:41:41.619] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:41:41 raspberrypi PISCSI[1245]: [2024-07-22 16:41:41.619] [trace] (ID 6) - Command phase
Jul 22 16:41:41 raspberrypi PISCSI[1245]: [2024-07-22 16:41:41.619] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $000000000000
Jul 22 16:41:41 raspberrypi PISCSI[1245]: [2024-07-22 16:41:41.619] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:41:41 raspberrypi PISCSI[1245]: [2024-07-22 16:41:41.619] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:41:41 raspberrypi PISCSI[1245]: [2024-07-22 16:41:41.619] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:41:41 raspberrypi PISCSI[1245]: [2024-07-22 16:41:41.619] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:41 raspberrypi PISCSI[1245]: [2024-07-22 16:41:41.619] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:41:41 raspberrypi PISCSI[1245]: [2024-07-22 16:41:41.620] [trace] (ID 6) - Message In phase
Jul 22 16:41:41 raspberrypi PISCSI[1245]: [2024-07-22 16:41:41.620] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:41 raspberrypi PISCSI[1245]: [2024-07-22 16:41:41.620] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:41:41 raspberrypi PISCSI[1245]: [2024-07-22 16:41:41.620] [trace] (ID 6) - Bus Free phase
Jul 22 16:41:44 raspberrypi PISCSI[1245]: [2024-07-22 16:41:44.770] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:41:44 raspberrypi PISCSI[1245]: [2024-07-22 16:41:44.770] [trace] (ID 6) - Selection phase
Jul 22 16:41:44 raspberrypi PISCSI[1245]: [2024-07-22 16:41:44.770] [trace] (ID 6) - Selection completed
Jul 22 16:41:44 raspberrypi PISCSI[1245]: [2024-07-22 16:41:44.770] [trace] (ID 6) - Message Out phase
Jul 22 16:41:44 raspberrypi PISCSI[1245]: [2024-07-22 16:41:44.770] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:41:44 raspberrypi PISCSI[1245]: [2024-07-22 16:41:44.770] [trace] (ID 6) - Phase: msgout
Jul 22 16:41:44 raspberrypi PISCSI[1245]: [2024-07-22 16:41:44.770] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:41:44 raspberrypi PISCSI[1245]: [2024-07-22 16:41:44.771] [trace] (ID 6) - Command phase
Jul 22 16:41:44 raspberrypi PISCSI[1245]: [2024-07-22 16:41:44.771] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $000000000000
Jul 22 16:41:44 raspberrypi PISCSI[1245]: [2024-07-22 16:41:44.771] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:41:44 raspberrypi PISCSI[1245]: [2024-07-22 16:41:44.771] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:41:44 raspberrypi PISCSI[1245]: [2024-07-22 16:41:44.771] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:41:44 raspberrypi PISCSI[1245]: [2024-07-22 16:41:44.771] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:44 raspberrypi PISCSI[1245]: [2024-07-22 16:41:44.771] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:41:44 raspberrypi PISCSI[1245]: [2024-07-22 16:41:44.771] [trace] (ID 6) - Message In phase
Jul 22 16:41:44 raspberrypi PISCSI[1245]: [2024-07-22 16:41:44.771] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:44 raspberrypi PISCSI[1245]: [2024-07-22 16:41:44.772] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:41:44 raspberrypi PISCSI[1245]: [2024-07-22 16:41:44.772] [trace] (ID 6) - Bus Free phase
Jul 22 16:41:47 raspberrypi PISCSI[1245]: [2024-07-22 16:41:47.787] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:41:47 raspberrypi PISCSI[1245]: [2024-07-22 16:41:47.787] [trace] (ID 6) - Selection phase
Jul 22 16:41:47 raspberrypi PISCSI[1245]: [2024-07-22 16:41:47.787] [trace] (ID 6) - Selection completed
Jul 22 16:41:47 raspberrypi PISCSI[1245]: [2024-07-22 16:41:47.787] [trace] (ID 6) - Message Out phase
Jul 22 16:41:47 raspberrypi PISCSI[1245]: [2024-07-22 16:41:47.788] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:41:47 raspberrypi PISCSI[1245]: [2024-07-22 16:41:47.788] [trace] (ID 6) - Phase: msgout
Jul 22 16:41:47 raspberrypi PISCSI[1245]: [2024-07-22 16:41:47.788] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:41:47 raspberrypi PISCSI[1245]: [2024-07-22 16:41:47.788] [trace] (ID 6) - Command phase
Jul 22 16:41:47 raspberrypi PISCSI[1245]: [2024-07-22 16:41:47.788] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $000000000000
Jul 22 16:41:47 raspberrypi PISCSI[1245]: [2024-07-22 16:41:47.788] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:41:47 raspberrypi PISCSI[1245]: [2024-07-22 16:41:47.788] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:41:47 raspberrypi PISCSI[1245]: [2024-07-22 16:41:47.788] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:41:47 raspberrypi PISCSI[1245]: [2024-07-22 16:41:47.788] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:47 raspberrypi PISCSI[1245]: [2024-07-22 16:41:47.789] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:41:47 raspberrypi PISCSI[1245]: [2024-07-22 16:41:47.789] [trace] (ID 6) - Message In phase
Jul 22 16:41:47 raspberrypi PISCSI[1245]: [2024-07-22 16:41:47.789] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:47 raspberrypi PISCSI[1245]: [2024-07-22 16:41:47.789] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:41:47 raspberrypi PISCSI[1245]: [2024-07-22 16:41:47.789] [trace] (ID 6) - Bus Free phase
Jul 22 16:41:50 raspberrypi PISCSI[1245]: [2024-07-22 16:41:50.807] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:41:50 raspberrypi PISCSI[1245]: [2024-07-22 16:41:50.807] [trace] (ID 6) - Selection phase
Jul 22 16:41:50 raspberrypi PISCSI[1245]: [2024-07-22 16:41:50.807] [trace] (ID 6) - Selection completed
Jul 22 16:41:50 raspberrypi PISCSI[1245]: [2024-07-22 16:41:50.808] [trace] (ID 6) - Message Out phase
Jul 22 16:41:50 raspberrypi PISCSI[1245]: [2024-07-22 16:41:50.808] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:41:50 raspberrypi PISCSI[1245]: [2024-07-22 16:41:50.808] [trace] (ID 6) - Phase: msgout
Jul 22 16:41:50 raspberrypi PISCSI[1245]: [2024-07-22 16:41:50.808] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:41:50 raspberrypi PISCSI[1245]: [2024-07-22 16:41:50.808] [trace] (ID 6) - Command phase
Jul 22 16:41:50 raspberrypi PISCSI[1245]: [2024-07-22 16:41:50.808] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $000000000000
Jul 22 16:41:50 raspberrypi PISCSI[1245]: [2024-07-22 16:41:50.808] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:41:50 raspberrypi PISCSI[1245]: [2024-07-22 16:41:50.808] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:41:50 raspberrypi PISCSI[1245]: [2024-07-22 16:41:50.808] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:41:50 raspberrypi PISCSI[1245]: [2024-07-22 16:41:50.808] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:50 raspberrypi PISCSI[1245]: [2024-07-22 16:41:50.809] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:41:50 raspberrypi PISCSI[1245]: [2024-07-22 16:41:50.809] [trace] (ID 6) - Message In phase
Jul 22 16:41:50 raspberrypi PISCSI[1245]: [2024-07-22 16:41:50.809] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:50 raspberrypi PISCSI[1245]: [2024-07-22 16:41:50.809] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:41:50 raspberrypi PISCSI[1245]: [2024-07-22 16:41:50.809] [trace] (ID 6) - Bus Free phase
Jul 22 16:41:53 raspberrypi PISCSI[1245]: [2024-07-22 16:41:53.827] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:41:53 raspberrypi PISCSI[1245]: [2024-07-22 16:41:53.827] [trace] (ID 6) - Selection phase
Jul 22 16:41:53 raspberrypi PISCSI[1245]: [2024-07-22 16:41:53.827] [trace] (ID 6) - Selection completed
Jul 22 16:41:53 raspberrypi PISCSI[1245]: [2024-07-22 16:41:53.827] [trace] (ID 6) - Message Out phase
Jul 22 16:41:53 raspberrypi PISCSI[1245]: [2024-07-22 16:41:53.828] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:41:53 raspberrypi PISCSI[1245]: [2024-07-22 16:41:53.828] [trace] (ID 6) - Phase: msgout
Jul 22 16:41:53 raspberrypi PISCSI[1245]: [2024-07-22 16:41:53.828] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:41:53 raspberrypi PISCSI[1245]: [2024-07-22 16:41:53.828] [trace] (ID 6) - Command phase
Jul 22 16:41:53 raspberrypi PISCSI[1245]: [2024-07-22 16:41:53.828] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $000000000000
Jul 22 16:41:53 raspberrypi PISCSI[1245]: [2024-07-22 16:41:53.828] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:41:53 raspberrypi PISCSI[1245]: [2024-07-22 16:41:53.828] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:41:53 raspberrypi PISCSI[1245]: [2024-07-22 16:41:53.828] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:41:53 raspberrypi PISCSI[1245]: [2024-07-22 16:41:53.828] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:53 raspberrypi PISCSI[1245]: [2024-07-22 16:41:53.829] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:41:53 raspberrypi PISCSI[1245]: [2024-07-22 16:41:53.829] [trace] (ID 6) - Message In phase
Jul 22 16:41:53 raspberrypi PISCSI[1245]: [2024-07-22 16:41:53.829] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:53 raspberrypi PISCSI[1245]: [2024-07-22 16:41:53.829] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:41:53 raspberrypi PISCSI[1245]: [2024-07-22 16:41:53.829] [trace] (ID 6) - Bus Free phase
Jul 22 16:41:56 raspberrypi PISCSI[1245]: [2024-07-22 16:41:56.847] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:41:56 raspberrypi PISCSI[1245]: [2024-07-22 16:41:56.847] [trace] (ID 6) - Selection phase
Jul 22 16:41:56 raspberrypi PISCSI[1245]: [2024-07-22 16:41:56.847] [trace] (ID 6) - Selection completed
Jul 22 16:41:56 raspberrypi PISCSI[1245]: [2024-07-22 16:41:56.848] [trace] (ID 6) - Message Out phase
Jul 22 16:41:56 raspberrypi PISCSI[1245]: [2024-07-22 16:41:56.848] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:41:56 raspberrypi PISCSI[1245]: [2024-07-22 16:41:56.848] [trace] (ID 6) - Phase: msgout
Jul 22 16:41:56 raspberrypi PISCSI[1245]: [2024-07-22 16:41:56.848] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:41:56 raspberrypi PISCSI[1245]: [2024-07-22 16:41:56.848] [trace] (ID 6) - Command phase
Jul 22 16:41:56 raspberrypi PISCSI[1245]: [2024-07-22 16:41:56.848] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $000000000000
Jul 22 16:41:56 raspberrypi PISCSI[1245]: [2024-07-22 16:41:56.848] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:41:56 raspberrypi PISCSI[1245]: [2024-07-22 16:41:56.848] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:41:56 raspberrypi PISCSI[1245]: [2024-07-22 16:41:56.848] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:41:56 raspberrypi PISCSI[1245]: [2024-07-22 16:41:56.848] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:56 raspberrypi PISCSI[1245]: [2024-07-22 16:41:56.849] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:41:56 raspberrypi PISCSI[1245]: [2024-07-22 16:41:56.849] [trace] (ID 6) - Message In phase
Jul 22 16:41:56 raspberrypi PISCSI[1245]: [2024-07-22 16:41:56.849] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:41:56 raspberrypi PISCSI[1245]: [2024-07-22 16:41:56.849] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:41:56 raspberrypi PISCSI[1245]: [2024-07-22 16:41:56.849] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:00 raspberrypi PISCSI[1245]: [2024-07-22 16:42:00.044] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:00 raspberrypi PISCSI[1245]: [2024-07-22 16:42:00.044] [trace] (ID 6) - Selection phase
Jul 22 16:42:00 raspberrypi PISCSI[1245]: [2024-07-22 16:42:00.044] [trace] (ID 6) - Selection completed
Jul 22 16:42:00 raspberrypi PISCSI[1245]: [2024-07-22 16:42:00.044] [trace] (ID 6) - Message Out phase
Jul 22 16:42:00 raspberrypi PISCSI[1245]: [2024-07-22 16:42:00.044] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:00 raspberrypi PISCSI[1245]: [2024-07-22 16:42:00.044] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:00 raspberrypi PISCSI[1245]: [2024-07-22 16:42:00.044] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:00 raspberrypi PISCSI[1245]: [2024-07-22 16:42:00.044] [trace] (ID 6) - Command phase
Jul 22 16:42:00 raspberrypi PISCSI[1245]: [2024-07-22 16:42:00.044] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $000000000000
Jul 22 16:42:00 raspberrypi PISCSI[1245]: [2024-07-22 16:42:00.045] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:42:00 raspberrypi PISCSI[1245]: [2024-07-22 16:42:00.045] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:00 raspberrypi PISCSI[1245]: [2024-07-22 16:42:00.045] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:00 raspberrypi PISCSI[1245]: [2024-07-22 16:42:00.045] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:00 raspberrypi PISCSI[1245]: [2024-07-22 16:42:00.045] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:00 raspberrypi PISCSI[1245]: [2024-07-22 16:42:00.045] [trace] (ID 6) - Message In phase
Jul 22 16:42:00 raspberrypi PISCSI[1245]: [2024-07-22 16:42:00.045] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:00 raspberrypi PISCSI[1245]: [2024-07-22 16:42:00.045] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:00 raspberrypi PISCSI[1245]: [2024-07-22 16:42:00.045] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:04 raspberrypi PISCSI[1245]: [2024-07-22 16:42:04.827] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:04 raspberrypi PISCSI[1245]: [2024-07-22 16:42:04.827] [trace] (ID 6) - Selection phase
Jul 22 16:42:04 raspberrypi PISCSI[1245]: [2024-07-22 16:42:04.827] [trace] (ID 6) - Selection completed
Jul 22 16:42:04 raspberrypi PISCSI[1245]: [2024-07-22 16:42:04.828] [trace] (ID 6) - Message Out phase
Jul 22 16:42:04 raspberrypi PISCSI[1245]: [2024-07-22 16:42:04.828] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:04 raspberrypi PISCSI[1245]: [2024-07-22 16:42:04.828] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:04 raspberrypi PISCSI[1245]: [2024-07-22 16:42:04.828] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:04 raspberrypi PISCSI[1245]: [2024-07-22 16:42:04.828] [trace] (ID 6) - Command phase
Jul 22 16:42:04 raspberrypi PISCSI[1245]: [2024-07-22 16:42:04.828] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $000000000000
Jul 22 16:42:04 raspberrypi PISCSI[1245]: [2024-07-22 16:42:04.828] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:42:04 raspberrypi PISCSI[1245]: [2024-07-22 16:42:04.828] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:04 raspberrypi PISCSI[1245]: [2024-07-22 16:42:04.828] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:04 raspberrypi PISCSI[1245]: [2024-07-22 16:42:04.828] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:04 raspberrypi PISCSI[1245]: [2024-07-22 16:42:04.829] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:04 raspberrypi PISCSI[1245]: [2024-07-22 16:42:04.829] [trace] (ID 6) - Message In phase
Jul 22 16:42:04 raspberrypi PISCSI[1245]: [2024-07-22 16:42:04.829] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:04 raspberrypi PISCSI[1245]: [2024-07-22 16:42:04.829] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:04 raspberrypi PISCSI[1245]: [2024-07-22 16:42:04.829] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.096] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.096] [trace] (ID 6) - Selection phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.096] [trace] (ID 6) - Selection completed
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.096] [trace] (ID 6) - Message Out phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.096] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.096] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.096] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.096] [trace] (ID 6) - Command phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.096] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $000000000000
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.096] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.097] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.097] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.097] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.097] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.097] [trace] (ID 6) - Message In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.097] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.097] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.097] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.098] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.098] [trace] (ID 6) - Selection phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.098] [trace] (ID 6) - Selection completed
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.098] [trace] (ID 6) - Message Out phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.098] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.098] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.099] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.099] [trace] (ID 6) - Command phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.099] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $000000000000
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.099] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.099] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.099] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.099] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.099] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.099] [trace] (ID 6) - Message In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.100] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.100] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.100] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.101] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.101] [trace] (ID 6) - Selection phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.101] [trace] (ID 6) - Selection completed
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.101] [trace] (ID 6) - Message Out phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.101] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.101] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.101] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.101] [trace] (ID 6) - Command phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.101] [trace] (ID 6) - Controller is executing ReadToc, CDB $43020200000000045000
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.101] [debug] (ID:LUN 6:0) - Device is executing ReadToc ($43)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.101] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.101] [trace] (ID 6) - Data In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.102] [trace] (ID 6) - Sending data, offset: 0, length: 1104
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.106] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.106] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.107] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.107] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.107] [trace] (ID 6) - Message In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.107] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.107] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.107] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.108] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.108] [trace] (ID 6) - Selection phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.108] [trace] (ID 6) - Selection completed
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.108] [trace] (ID 6) - Message Out phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.108] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.108] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.108] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.108] [trace] (ID 6) - Command phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.109] [trace] (ID 6) - Controller is executing ReadToc, CDB $43000000000000032400
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.109] [debug] (ID:LUN 6:0) - Device is executing ReadToc ($43)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.109] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.109] [trace] (ID 6) - Data In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.109] [trace] (ID 6) - Sending data, offset: 0, length: 804
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.113] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.113] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.113] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.113] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.113] [trace] (ID 6) - Message In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.113] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.113] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.114] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.116] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.116] [trace] (ID 6) - Selection phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.116] [trace] (ID 6) - Selection completed
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.116] [trace] (ID 6) - Message Out phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.116] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.116] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.116] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.116] [trace] (ID 6) - Command phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.117] [trace] (ID 6) - Controller is executing ReadToc, CDB $43000500000000071e00
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.117] [debug] (ID:LUN 6:0) - Device is executing ReadToc ($43)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.117] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.117] [trace] (ID 6) - Data In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.117] [trace] (ID 6) - Sending data, offset: 0, length: 1822
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.125] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.125] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.125] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.125] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.125] [trace] (ID 6) - Message In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.125] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.126] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.126] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.127] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.127] [trace] (ID 6) - Selection phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.127] [trace] (ID 6) - Selection completed
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.127] [trace] (ID 6) - Message Out phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.127] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.127] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.127] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.127] [trace] (ID 6) - Command phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.127] [trace] (ID 6) - Controller is executing ReadToc, CDB $43000100000000000c40
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.127] [debug] (ID:LUN 6:0) - Device is executing ReadToc ($43)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.127] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.128] [trace] (ID 6) - Data In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.128] [trace] (ID 6) - Sending data, offset: 0, length: 12
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.128] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.128] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.128] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.128] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.128] [trace] (ID 6) - Message In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.128] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.129] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.129] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.129] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.130] [trace] (ID 6) - Selection phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.130] [trace] (ID 6) - Selection completed
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.130] [trace] (ID 6) - Message Out phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.130] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.130] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.130] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.130] [trace] (ID 6) - Command phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.130] [trace] (ID 6) - Controller is executing ReadToc, CDB $43000100000000000c40
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.130] [debug] (ID:LUN 6:0) - Device is executing ReadToc ($43)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.130] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.130] [trace] (ID 6) - Data In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.131] [trace] (ID 6) - Sending data, offset: 0, length: 12
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.131] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.131] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.131] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.131] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.131] [trace] (ID 6) - Message In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.131] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.132] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.132] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.133] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.133] [trace] (ID 6) - Selection phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.133] [trace] (ID 6) - Selection completed
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.133] [trace] (ID 6) - Message Out phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.133] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.133] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.133] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.133] [trace] (ID 6) - Command phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.133] [trace] (ID 6) - Controller is executing Read10, CDB $28000000010000000100
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.133] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.134] [trace] (ID:LUN 6:0) - READ/WRITE/VERIFY/SEEK, start block: $00000100, blocks: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.134] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.134] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.134] [trace] (ID:LUN 6:0) - Length is 2048
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.134] [trace] (ID 6) - Data In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.134] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.143] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.143] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.143] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.143] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.143] [trace] (ID 6) - Message In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.143] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.144] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.144] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.144] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.145] [trace] (ID 6) - Selection phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.145] [trace] (ID 6) - Selection completed
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.145] [trace] (ID 6) - Message Out phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.145] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.145] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.145] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.145] [trace] (ID 6) - Command phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.145] [trace] (ID 6) - Controller is executing ReadToc, CDB $43000100000000000c40
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.145] [debug] (ID:LUN 6:0) - Device is executing ReadToc ($43)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.145] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.145] [trace] (ID 6) - Data In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.146] [trace] (ID 6) - Sending data, offset: 0, length: 12
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.146] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.146] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.146] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.146] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.146] [trace] (ID 6) - Message In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.146] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.147] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.147] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.148] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.148] [trace] (ID 6) - Selection phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.148] [trace] (ID 6) - Selection completed
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.148] [trace] (ID 6) - Message Out phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.148] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.148] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.148] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.148] [trace] (ID 6) - Command phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.148] [trace] (ID 6) - Controller is executing Read10, CDB $28000000001000000100
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.149] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.149] [trace] (ID:LUN 6:0) - READ/WRITE/VERIFY/SEEK, start block: $00000010, blocks: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.149] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.149] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.149] [trace] (ID:LUN 6:0) - Length is 2048
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.149] [trace] (ID 6) - Data In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.149] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.158] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.158] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.158] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.159] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.159] [trace] (ID 6) - Message In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.159] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.159] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.159] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.160] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.160] [trace] (ID 6) - Selection phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.160] [trace] (ID 6) - Selection completed
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.160] [trace] (ID 6) - Message Out phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.160] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.160] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.160] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.161] [trace] (ID 6) - Command phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.161] [trace] (ID 6) - Controller is executing Read10, CDB $28000000001000000300
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.161] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.161] [trace] (ID:LUN 6:0) - READ/WRITE/VERIFY/SEEK, start block: $00000010, blocks: 3
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.161] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.161] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.161] [trace] (ID:LUN 6:0) - Length is 2048
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.161] [trace] (ID 6) - Data In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.161] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.170] [trace] (ID 6) - Command: $28
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.170] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.170] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.170] [trace] (ID 6) - Processing after data collection
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.171] [trace] (ID 6) - Continuing to send
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.171] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.179] [trace] (ID 6) - Command: $28
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.179] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.179] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.179] [trace] (ID 6) - Processing after data collection
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.179] [trace] (ID 6) - Continuing to send
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.179] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.188] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.188] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.188] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.188] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.188] [trace] (ID 6) - Message In phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.188] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.188] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.189] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.190] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.190] [trace] (ID 6) - Selection phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.190] [trace] (ID 6) - Selection completed
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.190] [trace] (ID 6) - Message Out phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.190] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.190] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.190] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.190] [trace] (ID 6) - Command phase
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.190] [trace] (ID 6) - Controller is executing Read10, CDB $28000000001700000100
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.190] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.190] [trace] (ID:LUN 6:0) - READ/WRITE/VERIFY/SEEK, start block: $00000017, blocks: 1
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.191] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:07 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.191] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.191] [trace] (ID:LUN 6:0) - Length is 2048
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.191] [trace] (ID 6) - Data In phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.191] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.200] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.200] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.200] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.200] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.200] [trace] (ID 6) - Message In phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.200] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.200] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.200] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.207] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.207] [trace] (ID 6) - Selection phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.207] [trace] (ID 6) - Selection completed
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.207] [trace] (ID 6) - Message Out phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.207] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.207] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.208] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.208] [trace] (ID 6) - Command phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.208] [trace] (ID 6) - Controller is executing Read10, CDB $28000000001700000100
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.208] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.208] [trace] (ID:LUN 6:0) - READ/WRITE/VERIFY/SEEK, start block: $00000017, blocks: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.208] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.208] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.208] [trace] (ID:LUN 6:0) - Length is 2048
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.208] [trace] (ID 6) - Data In phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.208] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.214] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.215] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.215] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.215] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.215] [trace] (ID 6) - Message In phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.215] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.215] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.215] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.218] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.218] [trace] (ID 6) - Selection phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.218] [trace] (ID 6) - Selection completed
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.218] [trace] (ID 6) - Message Out phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.218] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.218] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.218] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.218] [trace] (ID 6) - Command phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.218] [trace] (ID 6) - Controller is executing Read10, CDB $2800000000b800000100
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.219] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.219] [trace] (ID:LUN 6:0) - READ/WRITE/VERIFY/SEEK, start block: $000000b8, blocks: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.219] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.219] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.219] [trace] (ID:LUN 6:0) - Length is 2048
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.219] [trace] (ID 6) - Data In phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.219] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.225] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.225] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.225] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.226] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.226] [trace] (ID 6) - Message In phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.226] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.226] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.226] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.226] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.226] [trace] (ID 6) - Selection phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.226] [trace] (ID 6) - Selection completed
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.226] [trace] (ID 6) - Message Out phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.226] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.226] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.227] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.227] [trace] (ID 6) - Command phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.227] [trace] (ID 6) - Controller is executing Read10, CDB $2800000000b900000100
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.227] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.227] [trace] (ID:LUN 6:0) - READ/WRITE/VERIFY/SEEK, start block: $000000b9, blocks: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.227] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.227] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.227] [trace] (ID:LUN 6:0) - Length is 2048
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.227] [trace] (ID 6) - Data In phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.227] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.234] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.234] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.234] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.234] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.234] [trace] (ID 6) - Message In phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.234] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.234] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.234] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.235] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.235] [trace] (ID 6) - Selection phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.235] [trace] (ID 6) - Selection completed
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.235] [trace] (ID 6) - Message Out phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.235] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.235] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.235] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.235] [trace] (ID 6) - Command phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.236] [trace] (ID 6) - Controller is executing Read10, CDB $2800000000ba00000100
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.236] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.236] [trace] (ID:LUN 6:0) - READ/WRITE/VERIFY/SEEK, start block: $000000ba, blocks: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.236] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.236] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.236] [trace] (ID:LUN 6:0) - Length is 2048
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.236] [trace] (ID 6) - Data In phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.236] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.242] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.243] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.243] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.243] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.243] [trace] (ID 6) - Message In phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.243] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.243] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.243] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.244] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.244] [trace] (ID 6) - Selection phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.244] [trace] (ID 6) - Selection completed
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.244] [trace] (ID 6) - Message Out phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.244] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.244] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.244] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.244] [trace] (ID 6) - Command phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.244] [trace] (ID 6) - Controller is executing Read10, CDB $2800000000bb00000100
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.245] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.245] [trace] (ID:LUN 6:0) - READ/WRITE/VERIFY/SEEK, start block: $000000bb, blocks: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.245] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.245] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.245] [trace] (ID:LUN 6:0) - Length is 2048
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.245] [trace] (ID 6) - Data In phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.245] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.251] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.251] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.251] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.251] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.251] [trace] (ID 6) - Message In phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.251] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.251] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.251] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.279] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.279] [trace] (ID 6) - Selection phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.279] [trace] (ID 6) - Selection completed
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.279] [trace] (ID 6) - Message Out phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.279] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.279] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.279] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.279] [trace] (ID 6) - Command phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.279] [trace] (ID 6) - Controller is executing Read10, CDB $28000000001800000100
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.280] [debug] (ID:LUN 6:0) - Device is executing Read10 ($28)
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.280] [trace] (ID:LUN 6:0) - READ/WRITE/VERIFY/SEEK, start block: $00000018, blocks: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.280] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.280] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.280] [trace] (ID:LUN 6:0) - Length is 2048
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.280] [trace] (ID 6) - Data In phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.280] [trace] (ID 6) - Sending data, offset: 0, length: 2048
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.286] [trace] (ID 6) - All data transferred, moving to next phase: datain
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.286] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.286] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.286] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.286] [trace] (ID 6) - Message In phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.286] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.289] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.289] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.847] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.847] [trace] (ID 6) - Selection phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.847] [trace] (ID 6) - Selection completed
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.847] [trace] (ID 6) - Message Out phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.847] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.847] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.847] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.848] [trace] (ID 6) - Command phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.848] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $000000000000
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.848] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.848] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.848] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.848] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.848] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.848] [trace] (ID 6) - Message In phase
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.848] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.848] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:08 raspberrypi PISCSI[1245]: [2024-07-22 16:42:07.848] [trace] (ID 6) - Bus Free phase
Jul 22 16:42:10 raspberrypi PISCSI[1245]: [2024-07-22 16:42:10.867] [trace] (ID 6) - ++++ Starting processing for initiator ID 7
Jul 22 16:42:10 raspberrypi PISCSI[1245]: [2024-07-22 16:42:10.867] [trace] (ID 6) - Selection phase
Jul 22 16:42:10 raspberrypi PISCSI[1245]: [2024-07-22 16:42:10.867] [trace] (ID 6) - Selection completed
Jul 22 16:42:10 raspberrypi PISCSI[1245]: [2024-07-22 16:42:10.868] [trace] (ID 6) - Message Out phase
Jul 22 16:42:10 raspberrypi PISCSI[1245]: [2024-07-22 16:42:10.868] [trace] (ID 6) - Receiving data, transfer length: 1 byte(s)
Jul 22 16:42:10 raspberrypi PISCSI[1245]: [2024-07-22 16:42:10.868] [trace] (ID 6) - Phase: msgout
Jul 22 16:42:10 raspberrypi PISCSI[1245]: [2024-07-22 16:42:10.868] [trace] (ID 6) - Received IDENTIFY message for LUN 0
Jul 22 16:42:10 raspberrypi PISCSI[1245]: [2024-07-22 16:42:10.868] [trace] (ID 6) - Command phase
Jul 22 16:42:10 raspberrypi PISCSI[1245]: [2024-07-22 16:42:10.868] [trace] (ID 6) - Controller is executing TestUnitReady, CDB $000000000000
Jul 22 16:42:10 raspberrypi PISCSI[1245]: [2024-07-22 16:42:10.868] [debug] (ID:LUN 6:0) - Device is executing TestUnitReady ($00)
Jul 22 16:42:10 raspberrypi PISCSI[1245]: [2024-07-22 16:42:10.868] [trace] (ID:LUN 6:0) - Device is ready
Jul 22 16:42:10 raspberrypi PISCSI[1245]: [2024-07-22 16:42:10.868] [trace] (ID 6) - Status phase, status is $00
Jul 22 16:42:10 raspberrypi PISCSI[1245]: [2024-07-22 16:42:10.868] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:10 raspberrypi PISCSI[1245]: [2024-07-22 16:42:10.869] [trace] (ID 6) - All data transferred, moving to next phase: status
Jul 22 16:42:10 raspberrypi PISCSI[1245]: [2024-07-22 16:42:10.869] [trace] (ID 6) - Message In phase
Jul 22 16:42:10 raspberrypi PISCSI[1245]: [2024-07-22 16:42:10.869] [trace] (ID 6) - Sending data, offset: 0, length: 1
Jul 22 16:42:10 raspberrypi PISCSI[1245]: [2024-07-22 16:42:10.869] [trace] (ID 6) - All data transferred, moving to next phase: msgin
Jul 22 16:42:10 raspberrypi PISCSI[1245]: [2024-07-22 16:42:10.869] [trace] (ID 6) - Bus Free phase
SavourySnaX commented 4 months ago

Both of the above were using the image i attached just before them.

uweseimet commented 4 months ago

With the image you provided I can reproduce the problem with my Atari, i.e. it is a general issue, not just something that happens with the Amiga. I expect to find out what's wrong quite soon. I hope I am not promising too much ;-).

In order for you to test any bugfix, do you have a Pi fast enough (i.e. not just a Pi Zero) to compile the bugfix branch from the sources, or would you need a binary package with the fix?

SavourySnaX commented 4 months ago

the only pi i have that is not in use, is a 400 - it can probably do it, although its not currently plugged in - If you ping here when you have a bugfix i can probably try and compile it on there. i can't be sure when i will get chance though, will depend on work etc.

uweseimet commented 4 months ago

No problem, I can provide a binary package with a fix I have just prepared. With this fix my Atari is now able to use the image you provided. I will get back to you as soon as the binary installation package is ready, which will take less than an hour.

uweseimet commented 4 months ago

Binaries for SCSI2Pi 3.4.1-devel are available now on https://www.scsi2pi.net/packages/develop/. Can you please test whether these resolve you problem, at least for one of your CD images?

SavourySnaX commented 4 months ago

Confirmed, both cds are now reading fine. thx

uweseimet commented 4 months ago

Great! Am I right that all of your issues are resolved with the fix I provided?

SavourySnaX commented 4 months ago

At least as far as I can test.. I`ll do some proper digging at the weekend when I have time, but this issue can be closed.

uweseimet commented 4 months ago

Sounds good, thank you for reporting and testing. I will most likely release SCSI2Pi 3.4.1 with this fix later today.