Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

Operation comparison at startup between v1.1 and RP2040 #128

Closed
Kurist2010 opened this issue Dec 24, 2022 · 35 comments
Closed

Operation comparison at startup between v1.1 and RP2040 #128

Kurist2010 opened this issue Dec 24, 2022 · 35 comments

Comments

@Kurist2010
Copy link

Kurist2010 commented Dec 24, 2022

This is the debug log when the same SD card is started with 1.1, RP2040 and PC-9821 respectively. RP2040 is not recognized by PC-9821.

After negotiating at 10MB/s, the RP2040 somehow resets the bus.

[0ms] Platform: ZuluSCSI v1.1
[0ms] FW Version: 1.2.0-release Dec 21 2022 18:21:02
[0ms] DIPSW3 is ON: Enabling SCSI termination
[1ms] DIPSW2 is ON: enabling debug messages
[2ms] Optional GreenPAK detected, loading firmware
[54ms] GreenPAK firmware successfully loaded
[170ms] SD card detected, FAT64 volume size: 241096 MB
[170ms] SD MID: 0x74, OID: 0x4A 0x60
[170ms] SD Name: SDU1 
[171ms] SD Date: 4/2021
[171ms] SD Serial: ----------
[173ms] Reading configuration from zuluscsi.ini
[173ms] Active configuration:
[177ms] -- SelectionDelay: 255
[181ms] -- EnableSCSI2 is on
[1164ms] Finding HDD images in directory /:
[1165ms] -- Opening /HD00_imaged.hda for id:0 lun:0
[1166ms] ---- Image file is contiguous, SD card sectors 134656 to 8523264
[1166ms] ---- Read prefetch enabled: 8192 bytes
[1221ms] SCSI ID:0 BlockSize:512 Type:0 Quirks:0 ImageSize:4194304kB
[1723ms] SCSI PHY operating mode: GREENPAK_DMA
[1723ms] Initialization complete!
[25230ms] DBG BUS RESET
[27583ms] DBG BUS RESET
[32114ms] DBG -- BUS_BUSY
[32114ms] DBG ---- SELECTION: 0
[32115ms] DBG ---- MESSAGE_OUT
[32116ms] DBG ------ OUT: 0xC0 
[32116ms] DBG ------ OUT: 0x01 
[32117ms] DBG ------ OUT: 0x02 
[32117ms] DBG ------ OUT: 0x03 
[32117ms] DBG ------ OUT: 0x01 
[32118ms] DBG ---- MESSAGE_IN
[32118ms] DBG ------ IN: 0x01 0x02 0x03 0x00 
[32121ms] DBG ---- MESSAGE_OUT
[32123ms] DBG ------ OUT: 0x01 
[32124ms] DBG ------ OUT: 0x03 
[32124ms] DBG ------ OUT: 0x01 
[32124ms] DBG ------ OUT: 0x0C 
[32125ms] DBG ------ OUT: 0x0F 
[32125ms] SCSI ID 0 negotiated synchronous mode 10 MB/s (period 4x25 ns, offset 15 bytes)
[32126ms] DBG ---- MESSAGE_IN
[32126ms] DBG ------ IN: 0x01 0x03 0x01 0x19 0x0F 
[32129ms] DBG ---- COMMAND: Inquiry
[32129ms] DBG ------ OUT: 0x12 0x00 0x00 0x00 0x08 0x00 
[32129ms] DBG ---- DATA_IN, syncOffset 15 syncPeriod 25
[32130ms] DBG ---- Total IN: 8 OUT: 0 CHECKSUM: 4124
[32130ms] DBG ---- STATUS: 0 GOOD
[32146ms] DBG ---- MESSAGE_IN
[32147ms] DBG ------ IN: 0x00 
[32147ms] DBG -- BUS_FREE
[10ms] Platform: ZuluSCSI RP2040
[10ms] FW Version: 1.2.0-release Dec 21 2022 18:21:45
[11ms] DIP switch settings: debug log 1, termination 1
[11ms] SCSI termination is enabled
[12ms] Flash chip size: 2048 kB
[14ms] SCSI target/disk mode selected by DIP switch, acting as a SCSI disk
[23ms] SD card detected, FAT64 volume size: 241096 MB
[24ms] SD MID: 0x74, OID: 0x4A 0x60
[24ms] SD Name: SDU1 
[24ms] SD Date: 4/2021
[24ms] SD Serial: ----------
[27ms] Reading configuration from zuluscsi.ini
[27ms] Active configuration:
[32ms] -- SelectionDelay: 255
[37ms] -- EnableSCSI2 is on
[1209ms] Finding HDD images in directory /:
[1211ms] -- Opening /HD00_imaged.hda for id:0 lun:0
[1212ms] ---- Image file is contiguous, SD card sectors 134656 to 8523264
[1213ms] ---- Read prefetch enabled: 8192 bytes
[1279ms] -- Platform supports ROM drive up to 1692 kB
[1280ms] ---- ROM drive image not detected
[1280ms] SCSI ID:0 BlockSize:512 Type:0 Quirks:0 ImageSize:4194304kB
[1781ms] Initialization complete!
[24907ms] DBG BUS RESET
[27250ms] DBG BUS RESET
[31765ms] DBG ---- SELECTION: 0
[31766ms] DBG ---- MESSAGE_OUT
[31767ms] DBG ------ OUT: 0xC0 
[31767ms] DBG ------ OUT: 0x01 
[31768ms] DBG ------ OUT: 0x02 
[31768ms] DBG ------ OUT: 0x03 
[31768ms] DBG ------ OUT: 0x01 
[31769ms] DBG ---- MESSAGE_IN
[31769ms] DBG ------ IN: 0x01 0x02 0x03 0x00 
[31772ms] DBG ---- MESSAGE_OUT
[31774ms] DBG ------ OUT: 0x01 
[31775ms] DBG ------ OUT: 0x03 
[31775ms] DBG ------ OUT: 0x01 
[31775ms] DBG ------ OUT: 0x0C 
[31776ms] DBG ------ OUT: 0x0F 
[31776ms] SCSI ID 0 negotiated synchronous mode 10 MB/s (period 4x25 ns, offset 15 bytes)
[31777ms] DBG ---- MESSAGE_IN
[31777ms] DBG ------ IN: 0x01 0x03 0x01 0x19 0x0F 
[31785ms] DBG BUS RESET
[31786ms] DBG ---- COMMAND: Unknown
[31786ms] DBG ------ OUT: 0x80 0x00 0x00 0x00 0x00 0x00 
[31787ms] DBG -- BUS_FREE
@PetteriAimonen
Copy link
Collaborator

To debug whether this is a problem with synchronous mode, can you try with MaxSyncSpeed = 0 in the .ini file?

@Kurist2010
Copy link
Author

I tried setting MaxSyncSpeed = 0 , but nothing changed.

Excerpt from v1.1

[32109ms] DBG ---- MESSAGE_IN
[32109ms] DBG ------ IN: 0x01 0x02 0x03 0x00 
[32112ms] DBG ---- MESSAGE_OUT
[32114ms] DBG ------ OUT: 0x01 
[32115ms] DBG ------ OUT: 0x03 
[32115ms] DBG ------ OUT: 0x01 
[32115ms] DBG ------ OUT: 0x0C 
[32116ms] DBG ------ OUT: 0x0F 
[32116ms] DBG ---- MESSAGE_IN
[32116ms] DBG ------ IN: 0x01 0x03 0x01 0x00 0x00 
[32119ms] DBG ---- COMMAND: Inquiry
[32119ms] DBG ------ OUT: 0x12 0x00 0x00 0x00 0x08 0x00 
[32119ms] DBG ---- DATA_IN
[32120ms] DBG ---- Total IN: 8 OUT: 0 CHECKSUM: 4124
[32120ms] DBG ---- STATUS: 0 GOOD

Excerpt from RP2040

[31765ms] DBG ---- MESSAGE_IN
[31765ms] DBG ------ IN: 0x01 0x02 0x03 0x00 
[31768ms] DBG ---- MESSAGE_OUT
[31771ms] DBG ------ OUT: 0x01 
[31771ms] DBG ------ OUT: 0x03 
[31771ms] DBG ------ OUT: 0x01 
[31772ms] DBG ------ OUT: 0x0C 
[31772ms] DBG ------ OUT: 0x0F 
[31772ms] DBG ---- MESSAGE_IN
[31773ms] DBG ------ IN: 0x01 0x03 0x01 0x00 0x00 
[31781ms] DBG BUS RESET
[31781ms] DBG ---- COMMAND: Unknown
[31781ms] DBG ------ OUT: 0x80 0x00 0x00 0x00 0x00 0x00 

@PetteriAimonen
Copy link
Collaborator

That's interesting. The bus reset is most likely coming from the host during the command reception (bus reset terminates the command reading, which is why it gets logged immediately after the reset).

I'm currently trying to be on a vacation so in-depth debugging will have to wait.
Testing previous firmware version 1.1.5 is useful also, because firmware 1.2.0 had a lot of RP2040 low level changes.

@Kurist2010
Copy link
Author

Firmware 1.1.5 also causes a bus reset at the timing of Inquiry, but TestUnitReady is notified after that. In any case, it cannot be recognized from the BIOS because Inquiry is NG.
Zuluscsi.ini is set to MaxSyncSpeed = 0.

Please check back after the holidays are over.

[10ms] Platform: ZuluSCSI RP2040
[10ms] FW Version: 1.1.5-release Dec  5 2022 23:42:09

              (omit)

[30084ms] DBG ---- MESSAGE_IN
[30084ms] DBG ------ IN: 0x01 0x02 0x03 0x00 
[30087ms] DBG ---- MESSAGE_OUT
[30089ms] DBG ------ OUT: 0x01 
[30090ms] DBG ------ OUT: 0x03 
[30090ms] DBG ------ OUT: 0x01 
[30090ms] DBG ------ OUT: 0x0C 
[30091ms] DBG ------ OUT: 0x0F 
[30091ms] DBG ---- MESSAGE_IN
[30091ms] DBG ------ IN: 0x01 0x03 0x01 0x00 0x00 
[30099ms] DBG BUS RESET
[30100ms] DBG ---- COMMAND: TestUnitReady
[30100ms] DBG ------ OUT: 0x00 0x00 0x00 0x00 0x00 0x00 
[30105ms] DBG -- BUS_FREE

@PetteriAimonen
Copy link
Collaborator

The "TestUnitReady" is probably just due to the reset - it has the 0x00 command code, and the bus reset aborts the command reading. In any case the command won't be handled because the bus reset causes immediate abort of the command.

I'll try to compare the SCSI bus waveforms of RP2040 and V1.1 when I get back from vacation in January, but it may be that there is something weird that occurs only on that platform.

PetteriAimonen added a commit that referenced this issue Jan 31, 2023
It seems that some hosts like PC-9821 have low tolerance for delay
between the different phase signals toggling. The Cortex-M0 processor
slow bit twiddling instructions caused around 100 ns delay before
this change. The signals are now toggled simultaneously.
@PetteriAimonen
Copy link
Collaborator

Sorry for the delay, it took me longer than expected to get back to this.

Studying the waveforms, the only significant difference I see at this point of communication is that RP2040 has longer delay between toggling MSG and IO control signals.

@Kurist2010 I have a test build here that you could try (download zip at bottom of page):
https://github.com/ZuluSCSI/ZuluSCSI-firmware/actions/runs/4052977881

@Kurist2010
Copy link
Author

I haven't changed the SCSI HA (AHA-2940UW/J) settings, but the LED lights up momentarily at the timing when it seems that an inquiry was made from the BIOS when rebooting, but there was no access log. Of course there is no recognition from BIOS. Just to be sure, I also tried 1.15 and 1.20, but it's the same.

If you access RP2040 using a tool (SCCTL) after starting DOS, the debug log will be output, so I think there is no connection difference.

@PetteriAimonen
Copy link
Collaborator

Hmm, interesting - especially as I'm also using AHA-2940UW to test, but on a more modern machine and running Linux.

Even if there is no visible difference, could you get me the debug log from the test build?

@Kurist2010
Copy link
Author

I got the debug log for 1.2.1-devel.

[10ms] Platform: ZuluSCSI RP2040
[10ms] FW Version: 1.2.1-devel Jan 31 2023 10:12:56
[11ms] DIP switch settings: debug log 1, termination 0
[11ms] NOTE: SCSI termination is disabled
[12ms] Flash chip size: 2048 kB
[14ms] SCSI target/disk mode selected by DIP switch, acting as a SCSI disk
[23ms] SD card detected, FAT64 volume size: 241096 MB

Omit the SD card information.

[27ms] Reading configuration from zuluscsi.ini
[28ms] Active configuration:
[32ms] -- SelectionDelay: 255
[38ms] -- EnableSCSI2 is on
[1231ms] Finding HDD images in directory /:
[1233ms] -- Opening /HD00_imaged.hda for id:0 lun:0
[1234ms] ---- Image file is contiguous, SD card sectors 134656 to 8523264
[1235ms] ---- Read prefetch enabled: 8192 bytes
[1303ms] -- Platform supports ROM drive up to 1692 kB
[1304ms] ---- ROM drive image not detected
[1304ms] SCSI ID:0 BlockSize:512 Type:0 Quirks:0 ImageSize:4194304kB
[1805ms] Initialization complete!
s] DBG -- BUS_FREE
[108649ms] DBG -- BUS_BUSY
[108649ms] DBG -- BUS_FREE
[108650ms] DBG -- BUS_BUSY
[108650ms] DBG -- BUS_FREE

Only BUS FREE and BUS BUSY are omitted.

[112661ms] DBG -- BUS_FREE
[114745ms] DBG ---- SELECTION: 0
[114746ms] DBG ---- MESSAGE_OUT
[114747ms] DBG ------ OUT: 0xC0 
[114747ms] DBG ---- COMMAND: Inquiry
[114747ms] DBG ------ OUT: 0x12 0x00 0x00 0x00 0x05 0x00 
[114748ms] DBG ---- DATA_IN
[114748ms] DBG ---- Total IN: 5 OUT: 0 CHECKSUM: 32800
[114749ms] DBG ---- STATUS: 0 GOOD
[114848ms] DBG ---- MESSAGE_IN
[114848ms] DBG ------ IN: 0x00 
[114849ms] DBG -- BUS_FREE

This is the state after device scanning at MS-DOS startup (not recognized when ASPI8DOS.SYS is installed) and SCCTL startup. Some parts are in Japanese, but you should be able to understand what you need.

RP2040

@PetteriAimonen
Copy link
Collaborator

Ok, it seems to get further, because there is no BUS RESET in this log, and it at least shows up in the list.

I assume in this newest log, termination is disabled on purpose, i.e. you have other device doing termination?

It seems to have trouble reacting to the selection pulse now - a quite different problem than in the earlier logs where responding to selection worked ok.

Would it be possible for you to try the new firmware in a configuration equivalent to your earlier tests, i.e. at the terminating position? Just in case that is somehow affecting the signal characteristics.

@Kurist2010
Copy link
Author

Since I wanted to boot MS-DOS, I connected RaSCSI after RP2040 and turned off the terminator.
I removed RaSCSI and took debug log again. BUS RESET is the same as before.

[10ms] Platform: ZuluSCSI RP2040
[10ms] FW Version: 1.2.1-devel Jan 31 2023 10:12:56
[11ms] DIP switch settings: debug log 1, termination 1
[11ms] SCSI termination is enabled
[12ms] Flash chip size: 2048 kB
[14ms] SCSI target/disk mode selected by DIP switch, acting as a SCSI disk
[23ms] SD card detected, FAT64 volume size: 241096 MB
[24ms] SD MID: 0x74, OID: 0x4A 0x60

omit

[27ms] Reading configuration from zuluscsi.ini
[27ms] Active configuration:
[32ms] -- SelectionDelay: 255
[38ms] -- EnableSCSI2 is on
[1231ms] Finding HDD images in directory /:
[1233ms] -- Opening /HD00_imaged.hda for id:0 lun:0
[1234ms] ---- Image file is contiguous, SD card sectors 134656 to 8523264
[1235ms] ---- Read prefetch enabled: 8192 bytes
[1303ms] -- Platform supports ROM drive up to 1692 kB
[1304ms] ---- ROM drive image not detected
[1304ms] SCSI ID:0 BlockSize:512 Type:0 Quirks:0 ImageSize:4194304kB
[1805ms] Initialization complete!
[24901ms] DBG BUS RESET
[27245ms] DBG BUS RESET
[31758ms] DBG ---- SELECTION: 0
[31759ms] DBG ---- MESSAGE_OUT
[31759ms] DBG ------ OUT: 0xC0 
[31760ms] DBG ------ OUT: 0x01 
[31760ms] DBG ------ OUT: 0x02 
[31761ms] DBG ------ OUT: 0x03 
[31761ms] DBG ------ OUT: 0x01 
[31761ms] DBG ---- MESSAGE_IN
[31762ms] DBG ------ IN: 0x01 0x02 0x03 0x00 
[31765ms] DBG ---- MESSAGE_OUT
[31767ms] DBG ------ OUT: 0x01 
[31768ms] DBG ------ OUT: 0x03 
[31768ms] DBG ------ OUT: 0x01 
[31768ms] DBG ------ OUT: 0x0C 
[31768ms] DBG ------ OUT: 0x0F 
[31769ms] DBG ---- MESSAGE_IN
[31769ms] DBG ------ IN: 0x01 0x03 0x01 0x00 0x00 
[31777ms] DBG BUS RESET
[31777ms] DBG ---- COMMAND: Unknown
[31778ms] DBG ------ OUT: 0x80 0x00 0x00 0x00 0x00 0x00 
[31778ms] DBG -- BUS_FREE

aperezbios added a commit that referenced this issue Feb 6, 2023
RP2040: Reduce delay between phase signal changes (#128)
@aperezbios
Copy link
Collaborator

@Kurist2010 it seems you tested the development build before the pull request was merged. Can you please re-download the nightly image, and try again? Thanks

@PetteriAimonen
Copy link
Collaborator

PetteriAimonen commented Feb 14, 2023

@aperezbios Based on timestamp (Jan 31 2023 10:12:56) it is the correct build from the development branch that I linked.

I don't currently know what could be causing this problem, as far as I can tell there should be no difference between RP2040 and GD32 models that should affect this.

@Kurist2010
Copy link
Author

I checked with nightly image 2023-02-09 (fd9839b), but there was no particular change.

[10ms] Platform: ZuluSCSI RP2040
[10ms] FW Version: 1.2.1-devel Feb  9 2023 12:24:31
[11ms] DIP switch settings: debug log 1, termination 1
[11ms] SCSI termination is enabled
[12ms] Flash chip size: 2048 kB
[14ms] SCSI target/disk mode selected by DIP switch, acting as a SCSI disk
[23ms] SD card detected, FAT64 volume size: 241096 MB
[24ms] SD MID: 0x74, OID: 0x4A 0x60
[24ms] SD Name: SDU1 
[24ms] SD Date: 4/2021
            omit
[27ms] Reading configuration from zuluscsi.ini
[27ms] Active configuration:
[32ms] -- SelectionDelay: 255
[37ms] -- EnableSCSI2 is on
[1337ms] Finding HDD images in directory /:
[1339ms] -- Opening /HD00_imaged.hda for id:0 lun:0
[1340ms] ---- Image file is contiguous, SD card sectors 134656 to 8523264
[1341ms] ---- Read prefetch enabled: 8192 bytes
[1409ms] -- Platform supports ROM drive up to 1692 kB
[1410ms] ---- ROM drive image not detected
[1410ms] SCSI ID:0 BlockSize:512 Type:0 Quirks:0 ImageSize:4194304kB
[1911ms] Initialization complete!
[24836ms] DBG BUS RESET
[27179ms] DBG BUS RESET
[31692ms] DBG ---- SELECTION: 0
[31693ms] DBG ---- MESSAGE_OUT
[31693ms] DBG ------ OUT: 0xC0 
[31694ms] DBG ------ OUT: 0x01 
[31695ms] DBG ------ OUT: 0x02 
[31695ms] DBG ------ OUT: 0x03 
[31695ms] DBG ------ OUT: 0x01 
[31695ms] DBG ---- MESSAGE_IN
[31696ms] DBG ------ IN: 0x01 0x02 0x03 0x00 
[31699ms] DBG ---- MESSAGE_OUT
[31701ms] DBG ------ OUT: 0x01 
[31702ms] DBG ------ OUT: 0x03 
[31702ms] DBG ------ OUT: 0x01 
[31702ms] DBG ------ OUT: 0x0C 
[31703ms] DBG ------ OUT: 0x0F 
[31703ms] DBG ---- MESSAGE_IN
[31703ms] DBG ------ IN: 0x01 0x03 0x01 0x00 0x00 
[31711ms] DBG BUS RESET
[31711ms] DBG ---- COMMAND: Unknown
[31712ms] DBG ------ OUT: 0x80 0x00 0x00 0x00 0x00 0x00 
[31712ms] DBG -- BUS_FREE

@Kurist2010
Copy link
Author

Nightly image 2023-03-02 (4c17507) also had a bus reset.

@aperezbios
Copy link
Collaborator

@Kurist2010 bus resets are a normal part of SCSI, and any SCSI controller can re-set the bus at any time, for any reason, so that in and of itself isn't an issue.

@PetteriAimonen
Copy link
Collaborator

The issue here seems to be that something is making the SCSI host unhappy enough that it decides to abort the request with a bus reset.

Because the reset is happening only 8 milliseconds after the synchronous mode reply, it is not any timeout.
The only difference in RP2040 vs. V1.1 signals was a small difference in timing of mode signals, but fixing that didn't change anything.

@Kurist2010
Copy link
Author

Looking closely at the log, v1.1 shows BUS_BUSY between BUS RESET and SELECTION: 0, but with RP2040, SELECTION: 0 suddenly appears after BUS RESET. What is the difference?

@PetteriAimonen
Copy link
Collaborator

It's probably just random variation whether it has time to notice & log the BUS_BUSY state before the selection signal occurs (there is less than a millisecond time between them). It has no difference for operation, it is only logged to aid debugging in cases where host has problems selecting the device.

@PetteriAimonen
Copy link
Collaborator

In #172 it was noticed that RP2040 model was more sensitive to power supply variations than ZuluSCSI V1.1.

If you are still interested in testing and if the previous tests were by SCSI cable termination power, it is worth trying either the 4-pin power connector or USB power. Though the error behavior in your case is quite different, so this is just a guess.

@Kurist2010
Copy link
Author

It was only a power supply for termination.
The BUS RESET occurred even when power was applied to the BERG connector, and it occurred even when the USB was connected to the PC.

@PetteriAimonen
Copy link
Collaborator

Ok, thanks for info! I still hope to figure this out eventually, but currently I don't know what could possibly be causing the problems.

@aperezbios
Copy link
Collaborator

aperezbios commented May 5, 2023

@Kurist2010 can you try the latest firmware, which I released today? You can grab it here ZuluSCSI_RP2040_2023-05-04.bin

v2023.05.04 implements new voltage monitoring and logging, which was introduced in this commit 4cc78ca

@Kurist2010
Copy link
Author

I took a debug log without an external power supply.
The difference from before is SCSI-1 for confirmation of #123, and an image of ID5 is added. However, I didn't see any power related output in the logs.
It seems that the bus reset from BIOS is performed for each ID.

[10ms] Platform: ZuluSCSI RP2040
[10ms] FW Version: 23.05.04-release May  4 2023 16:37:33
[11ms] DIP switch settings: debug log 1, termination 1
[11ms] SCSI termination is enabled
[12ms] Flash chip size: 2048 kB
[14ms] SCSI target/disk mode selected by DIP switch, acting as a SCSI disk
[32ms] SD card detected, FAT64 volume size: 241096 MB
[32ms] SD MID: 0x74, OID: 0x4A 0x60
[32ms] SD Name: SDU1 
[33ms] SD Date: 4/2021
            omit
[37ms] Reading configuration from zuluscsi.ini
[38ms] Active configuration:
[40ms] -- SelectionDelay = 255
[40ms] -- EnableUnitAttention = No
[41ms] -- EnableSCSI2 = No
[42ms] -- EnableSelLatch = No
[43ms] -- MapLunsToIDs = No
[44ms] -- EnableParity = Yes
[152ms] Finding HDD images in directory /:
[155ms] -- Opening /HD0.hds for id:0 lun:0
[161ms] DBG ---- Image file is contiguous, SD card sectors 8529920 to 16918528
[162ms] ---- Read prefetch enabled: 8192 bytes
[163ms] -- Opening /HD5_256.hds for id:5 lun:0
[170ms] DBG ---- Image file is contiguous, SD card sectors 469894656 to 470142463
[170ms] ---- Read prefetch enabled: 8192 bytes
[177ms] -- Platform supports ROM drive up to 1692 kB
[178ms] ---- ROM drive image not detected
[178ms] SCSI ID:0 BlockSize:512 Type:0 Quirks:0 ImageSize:4194304kB
[179ms] SCSI ID:5 BlockSize:256 Type:0 Quirks:0 ImageSize:123904kB
[279ms] Initialization complete!
[23083ms] DBG BUS RESET
[25426ms] DBG BUS RESET
[29939ms] DBG ---- SELECTION: 0
[29941ms] DBG ---- MESSAGE_OUT
[29941ms] DBG ------ OUT: 0xC0 
[29942ms] DBG ------ OUT: 0x01 
[29942ms] DBG ------ OUT: 0x02 
[29943ms] DBG ------ OUT: 0x03 
[29943ms] DBG ------ OUT: 0x01 
[29943ms] DBG ---- MESSAGE_IN
[29944ms] DBG ------ IN: 0x01 0x02 0x03 0x00 
[29947ms] DBG ---- MESSAGE_OUT
[29949ms] DBG ------ OUT: 0x01 
[29949ms] DBG ------ OUT: 0x03 
[29950ms] DBG ------ OUT: 0x01 
[29950ms] DBG ------ OUT: 0x0C 
[29950ms] DBG ------ OUT: 0x0F 
[29951ms] DBG ---- MESSAGE_IN
[29951ms] DBG ------ IN: 0x01 0x03 0x01 0x00 0x00 
[29959ms] DBG BUS RESET
[29959ms] DBG ---- COMMAND: Unknown
[29960ms] DBG ------ OUT: 0x80 0x00 0x00 0x00 0x00 0x00 
[29961ms] DBG -- BUS_FREE
[79362ms] DBG ---- SELECTION: 5
[79363ms] DBG ---- MESSAGE_OUT
[79363ms] DBG ------ OUT: 0xC0 
[79364ms] DBG ------ OUT: 0x01 
[79364ms] DBG ------ OUT: 0x02 
[79365ms] DBG ------ OUT: 0x03 
[79365ms] DBG ------ OUT: 0x01 
[79365ms] DBG ---- MESSAGE_IN
[79366ms] DBG ------ IN: 0x01 0x02 0x03 0x00 
[79369ms] DBG ---- MESSAGE_OUT
[79371ms] DBG ------ OUT: 0x01 
[79372ms] DBG ------ OUT: 0x03 
[79372ms] DBG ------ OUT: 0x01 
[79372ms] DBG ------ OUT: 0x0C 
[79373ms] DBG ------ OUT: 0x0F 
[79373ms] DBG ---- MESSAGE_IN
[79373ms] DBG ------ IN: 0x01 0x03 0x01 0x00 0x00 
[79381ms] DBG BUS RESET
[79382ms] DBG ---- COMMAND: Unknown
[79382ms] DBG ------ OUT: 0x80 0xFF 0xFF 0xFF 0xFF 0xFF 
[79383ms] DBG -- BUS_FREE

@aperezbios
Copy link
Collaborator

@PetteriAimonen any idea what the two unknown SCSI commands are, in the log above?

@PetteriAimonen
Copy link
Collaborator

@aperezbios It's the same behavior as earlier, the host terminates request by issuing BUS RESET so the command is never received or processed, and is instead just garbage from the bus.

So something weird has to be happening in selection or the message phases.

It is probably related to this device re-issuing SCSI_ATN for second MESSAGE_OUT phase in a single request - it's a bit rare, but should work. And apparently does work on GD32.

@PetteriAimonen
Copy link
Collaborator

@Kurist2010 If you have time, here is a test build with more debug messages related to SCSI phase changes that you could try on the RP2040 (download zip at bottom of page):
https://github.com/ZuluSCSI/ZuluSCSI-firmware/actions/runs/4946094557

This seems to be related to how the two negotiations (SCSI wide bus negotiation and SCSI sync mode negotiation) are executed in same transaction. The above build tries to debug what happens there.

For some reason my AHA-2940UW doesn't send the wide bus negotiation at all, even though I have enabled it in the SCSI bios. Trying to disable wide mode in the Adaptec bios is worth trying also, though the negotiation should really work.

@Kurist2010
Copy link
Author

設定は前回と同様で試してみました。
ワイド設定無効については別途報告します。

[10ms] Platform: ZuluSCSI RP2040
[10ms] FW Version: 23.05.05-devel May 11 2023 09:11:12
[11ms] DIP switch settings: debug log 1, termination 1
[11ms] SCSI termination is enabled
[12ms] Flash chip size: 2048 kB
[14ms] SCSI target/disk mode selected by DIP switch, acting as a SCSI disk
[31ms] SD card detected, FAT64 volume size: 241096 MB
[31ms] SD MID: 0x74, OID: 0x4A 0x60
[32ms] SD Name: SDU1 
[32ms] SD Date: 4/2021
[32ms] SD Serial: (omit)
[37ms] Reading configuration from zuluscsi.ini
[38ms] Active configuration:
[39ms] -- SelectionDelay = 255
[40ms] -- EnableUnitAttention = No
[40ms] -- EnableSCSI2 = No
[41ms] -- EnableSelLatch = No
[42ms] -- MapLunsToIDs = No
[43ms] -- EnableParity = Yes
[151ms] Finding HDD images in directory /:
[154ms] -- Opening /HD0.hds for id:0 lun:0
[160ms] DBG ---- Image file is contiguous, SD card sectors 8529920 to 16918528
[160ms] ---- Read prefetch enabled: 8192 bytes
[162ms] -- Opening /HD5_256.hds for id:5 lun:0
[168ms] DBG ---- Image file is contiguous, SD card sectors 469894656 to 470142463
[169ms] ---- Read prefetch enabled: 8192 bytes
[176ms] -- Platform supports ROM drive up to 1692 kB
[176ms] ---- ROM drive image not detected
[177ms] SCSI ID:0 BlockSize:512 Type:0 Quirks:0 ImageSize:4194304kB
[178ms] SCSI ID:5 BlockSize:256 Type:0 Quirks:0 ImageSize:123904kB
[278ms] Initialization complete!
[24922ms] DBG BUS RESET, gpio 0x35FFFFFF
[27266ms] DBG BUS RESET, gpio 0x35FFFFFF
[31780ms] DBG ---- SELECTION: 0
[31781ms] DBG ---- scsiStatusSEL()
[31782ms] DBG ------ scsiStatusATN()=1
[31782ms] DBG ------ PHYPHASE 0->3 atnFlag 128 dev phase 2 gpio 0x1BFADEFF compatMode 2
[31783ms] DBG ---- MESSAGE_OUT
[31783ms] DBG ------ scsiReadByte()
[31784ms] DBG ------ OUT: 0xC0 
[31784ms] DBG ------ scsiStatusATN()=1
[31784ms] DBG ------ scsiReadByte()
[31785ms] DBG ------ OUT: 0x01 
[31785ms] DBG ------ scsiReadByte()
[31786ms] DBG ------ OUT: 0x02 
[31786ms] DBG ------ scsiReadByte()
[31786ms] DBG ------ OUT: 0x03 
[31787ms] DBG ------ scsiReadByte()
[31787ms] DBG ------ OUT: 0x01 
[31787ms] DBG ------ PHYPHASE 3->7 atnFlag 0 dev phase 2 gpio 0x3BFAD7FE compatMode 2
[31788ms] DBG ---- MESSAGE_IN
[31789ms] DBG ------ IN: 0x01 0x02 0x03 0x00 
[31792ms] DBG ------ scsiStatusATN()=1
[31792ms] DBG ------ PHYPHASE 7->3 atnFlag 1 dev phase 2 gpio 0x1BFFC7FF compatMode 2
[31793ms] DBG ---- MESSAGE_OUT
[31793ms] DBG ------ scsiReadByte()
[31794ms] DBG ------ OUT: 0x01 
[31794ms] DBG ------ scsiReadByte()
[31795ms] DBG ------ OUT: 0x03 
[31795ms] DBG ------ scsiReadByte()
[31795ms] DBG ------ OUT: 0x01 
[31796ms] DBG ------ scsiReadByte()
[31796ms] DBG ------ OUT: 0x0C 
[31797ms] DBG ------ scsiReadByte()
[31797ms] DBG ------ OUT: 0x0F 
[31797ms] DBG ------ PHYPHASE 3->7 atnFlag 0 dev phase 2 gpio 0x3BFAD6F0 compatMode 2
[31798ms] DBG ---- MESSAGE_IN
[31798ms] DBG ------ IN: 0x01 0x03 0x01 0x00 0x00 
[31802ms] DBG ------ scsiStatusATN()=0
[31802ms] DBG ------ PHYPHASE 7->2 atnFlag 0 dev phase 2 gpio 0x3BFFC7FF compatMode 2
[31803ms] DBG ------ scsiRead(6)
[31807ms] DBG BUS RESET, gpio 0x33FFF5FF
[31807ms] DBG ---- COMMAND: Unknown
[31807ms] DBG ------ OUT: 0x80 0x00 0x00 0x00 0x00 0x00 
[31808ms] DBG -- BUS_FREE
[79124ms] DBG -- BUS_BUSY
[79124ms] DBG -- BUS_FREE
[80683ms] DBG -- BUS_BUSY
[80684ms] DBG -- BUS_FREE
[81203ms] DBG ---- SELECTION: 5
[81205ms] DBG ---- scsiStatusSEL()
[81205ms] DBG ------ scsiStatusATN()=1
[81205ms] DBG ------ PHYPHASE 2->3 atnFlag 128 dev phase 2 gpio 0x1BFADEF0 compatMode 2
[81206ms] DBG ---- MESSAGE_OUT
[81207ms] DBG ------ scsiReadByte()
[81207ms] DBG ------ OUT: 0xC0 
[81207ms] DBG ------ scsiStatusATN()=1
[81208ms] DBG ------ scsiReadByte()
[81208ms] DBG ------ OUT: 0x01 
[81209ms] DBG ------ scsiReadByte()
[81209ms] DBG ------ OUT: 0x02 
[81209ms] DBG ------ scsiReadByte()
[81210ms] DBG ------ OUT: 0x03 
[81210ms] DBG ------ scsiReadByte()
[81210ms] DBG ------ OUT: 0x01 
[81211ms] DBG ------ PHYPHASE 3->7 atnFlag 0 dev phase 2 gpio 0x3BFED7FE compatMode 2
[81211ms] DBG ---- MESSAGE_IN
[81212ms] DBG ------ IN: 0x01 0x02 0x03 0x00 
[81215ms] DBG ------ scsiStatusATN()=1
[81215ms] DBG ------ PHYPHASE 7->3 atnFlag 1 dev phase 2 gpio 0x1BFBC7FF compatMode 2
[81216ms] DBG ---- MESSAGE_OUT
[81217ms] DBG ------ scsiReadByte()
[81217ms] DBG ------ OUT: 0x01 
[81218ms] DBG ------ scsiReadByte()
[81218ms] DBG ------ OUT: 0x03 
[81218ms] DBG ------ scsiReadByte()
[81219ms] DBG ------ OUT: 0x01 
[81219ms] DBG ------ scsiReadByte()
[81219ms] DBG ------ OUT: 0x0C 
[81220ms] DBG ------ scsiReadByte()
[81220ms] DBG ------ OUT: 0x0F 
[81221ms] DBG ------ PHYPHASE 3->7 atnFlag 0 dev phase 2 gpio 0x3BFAD6F0 compatMode 2
[81221ms] DBG ---- MESSAGE_IN
[81222ms] DBG ------ IN: 0x01 0x03 0x01 0x00 0x00 
[81225ms] DBG ------ scsiStatusATN()=0
[81225ms] DBG ------ PHYPHASE 7->2 atnFlag 0 dev phase 2 gpio 0x3BFFC7FF compatMode 2
[81226ms] DBG ------ scsiRead(6)
[81230ms] DBG BUS RESET, gpio 0x33FFF5FF
[81230ms] DBG ---- COMMAND: Unknown
[81231ms] DBG ------ OUT: 0x80 0xFF 0xFF 0xFF 0xFF 0xFF 
[81231ms] DBG -- BUS_FREE

@Kurist2010
Copy link
Author

This is when the wide setting is disabled.

[10ms] Platform: ZuluSCSI RP2040
[10ms] FW Version: 23.05.05-devel May 11 2023 09:11:12
[11ms] DIP switch settings: debug log 1, termination 1
[11ms] SCSI termination is enabled
[12ms] Flash chip size: 2048 kB
[14ms] SCSI target/disk mode selected by DIP switch, acting as a SCSI disk
[31ms] SD card detected, FAT64 volume size: 241096 MB
[32ms] SD MID: 0x74, OID: 0x4A 0x60
[32ms] SD Name: SDU1 
[32ms] SD Date: 4/2021
[33ms] SD Serial: (omit)
[37ms] Reading configuration from zuluscsi.ini
[38ms] Active configuration:
[39ms] -- SelectionDelay = 255
[40ms] -- EnableUnitAttention = No
[41ms] -- EnableSCSI2 = No
[41ms] -- EnableSelLatch = No
[42ms] -- MapLunsToIDs = No
[43ms] -- EnableParity = Yes
[151ms] Finding HDD images in directory /:
[155ms] -- Opening /HD0.hds for id:0 lun:0
[160ms] DBG ---- Image file is contiguous, SD card sectors 8529920 to 16918528
[161ms] ---- Read prefetch enabled: 8192 bytes
[162ms] -- Opening /HD5_256.hds for id:5 lun:0
[169ms] DBG ---- Image file is contiguous, SD card sectors 469894656 to 470142463
[170ms] ---- Read prefetch enabled: 8192 bytes
[177ms] -- Platform supports ROM drive up to 1692 kB
[177ms] ---- ROM drive image not detected
[178ms] SCSI ID:0 BlockSize:512 Type:0 Quirks:0 ImageSize:4194304kB
[179ms] SCSI ID:5 BlockSize:256 Type:0 Quirks:0 ImageSize:123904kB
[279ms] Initialization complete!
[24860ms] DBG BUS RESET, gpio 0x35FBFFFF
[27203ms] DBG BUS RESET, gpio 0x35FFFFFF
[31718ms] DBG ---- SELECTION: 0
[31719ms] DBG ---- scsiStatusSEL()
[31720ms] DBG ------ scsiStatusATN()=1
[31720ms] DBG ------ PHYPHASE 0->3 atnFlag 128 dev phase 2 gpio 0x1BFEDEFF compatMode 2
[31721ms] DBG ---- MESSAGE_OUT
[31721ms] DBG ------ scsiReadByte()
[31722ms] DBG ------ OUT: 0xC0 
[31722ms] DBG ------ scsiStatusATN()=1
[31722ms] DBG ------ scsiReadByte()
[31723ms] DBG ------ OUT: 0x01 
[31723ms] DBG ------ scsiReadByte()
[31724ms] DBG ------ OUT: 0x03 
[31724ms] DBG ------ scsiReadByte()
[31724ms] DBG ------ OUT: 0x01 
[31725ms] DBG ------ scsiReadByte()
[31725ms] DBG ------ OUT: 0x0C 
[31725ms] DBG ------ scsiReadByte()
[31726ms] DBG ------ OUT: 0x0F 
[31726ms] DBG ------ PHYPHASE 3->7 atnFlag 0 dev phase 2 gpio 0x3BFAD6F0 compatMode 2
[31727ms] DBG ---- MESSAGE_IN
[31727ms] DBG ------ IN: 0x01 0x03 0x01 0x00 0x00 
[31730ms] DBG ------ scsiStatusATN()=0
[31731ms] DBG ------ PHYPHASE 7->2 atnFlag 0 dev phase 2 gpio 0x3BFBC7FF compatMode 2
[31732ms] DBG ------ scsiRead(6)
[31735ms] DBG BUS RESET, gpio 0x33FBF5FF
[31736ms] DBG ---- COMMAND: Unknown
[31736ms] DBG ------ OUT: 0x80 0x00 0x00 0x00 0x00 0x00 
[31737ms] DBG -- BUS_FREE
[81138ms] DBG ---- SELECTION: 5
[81139ms] DBG ---- scsiStatusSEL()
[81139ms] DBG ------ scsiStatusATN()=1
[81140ms] DBG ------ PHYPHASE 2->3 atnFlag 128 dev phase 2 gpio 0x1BFADEF0 compatMode 2
[81141ms] DBG ---- MESSAGE_OUT
[81141ms] DBG ------ scsiReadByte()
[81141ms] DBG ------ OUT: 0xC0 
[81142ms] DBG ------ scsiStatusATN()=1
[81142ms] DBG ------ scsiReadByte()
[81143ms] DBG ------ OUT: 0x01 
[81143ms] DBG ------ scsiReadByte()
[81143ms] DBG ------ OUT: 0x03 
[81144ms] DBG ------ scsiReadByte()
[81144ms] DBG ------ OUT: 0x01 
[81144ms] DBG ------ scsiReadByte()
[81145ms] DBG ------ OUT: 0x0C 
[81145ms] DBG ------ scsiReadByte()
[81145ms] DBG ------ OUT: 0x0F 
[81146ms] DBG ------ PHYPHASE 3->7 atnFlag 0 dev phase 2 gpio 0x3BFAD6F0 compatMode 2
[81147ms] DBG ---- MESSAGE_IN
[81147ms] DBG ------ IN: 0x01 0x03 0x01 0x00 0x00 
[81150ms] DBG ------ scsiStatusATN()=0
[81150ms] DBG ------ PHYPHASE 7->2 atnFlag 0 dev phase 2 gpio 0x3BFBC7FF compatMode 2
[81151ms] DBG ------ scsiRead(6)
[81155ms] DBG BUS RESET, gpio 0x33FFF5FF
[81155ms] DBG ---- COMMAND: Unknown
[81156ms] DBG ------ OUT: 0x80 0xFF 0xFF 0xFF 0xFF 0xFF 
[81157ms] DBG -- BUS_FREE

@PetteriAimonen
Copy link
Collaborator

Thanks a lot for the log.

Looks like it happens even with a single MESSAGE_IN phase then. So much for that theory, but I'll try to figure something out.

@PetteriAimonen
Copy link
Collaborator

Hmm, does the same happen if also synchronous mode gets disabled in the SCSI bios? This could help differentiate whether the problem has anything to do with the MESSAGE_IN phase at all.

@Kurist2010
Copy link
Author

In addition to wide setting disabled, asynchronous setting.

[10ms] Platform: ZuluSCSI RP2040
[10ms] FW Version: 23.05.05-devel May 11 2023 09:11:12
[11ms] DIP switch settings: debug log 1, termination 1
[11ms] SCSI termination is enabled
[12ms] Flash chip size: 2048 kB
[14ms] SCSI target/disk mode selected by DIP switch, acting as a SCSI disk
[31ms] SD card detected, FAT64 volume size: 241096 MB
[31ms] SD MID: 0x74, OID: 0x4A 0x60
[32ms] SD Name: SDU1 
[32ms] SD Date: 4/2021
[32ms] SD Serial:    (omit)
[37ms] Reading configuration from zuluscsi.ini
[38ms] Active configuration:
[39ms] -- SelectionDelay = 255
[40ms] -- EnableUnitAttention = No
[40ms] -- EnableSCSI2 = No
[41ms] -- EnableSelLatch = No
[42ms] -- MapLunsToIDs = No
[43ms] -- EnableParity = Yes
[151ms] Finding HDD images in directory /:
[154ms] -- Opening /HD0.hds for id:0 lun:0
[160ms] DBG ---- Image file is contiguous, SD card sectors 8529920 to 16918528
[160ms] ---- Read prefetch enabled: 8192 bytes
[162ms] -- Opening /HD5_256.hds for id:5 lun:0
[168ms] DBG ---- Image file is contiguous, SD card sectors 469894656 to 470142463
[169ms] ---- Read prefetch enabled: 8192 bytes
[176ms] -- Platform supports ROM drive up to 1692 kB
[176ms] ---- ROM drive image not detected
[177ms] SCSI ID:0 BlockSize:512 Type:0 Quirks:0 ImageSize:4194304kB
[178ms] SCSI ID:5 BlockSize:256 Type:0 Quirks:0 ImageSize:123904kB
[278ms] Initialization complete!
[24857ms] DBG BUS RESET, gpio 0x35FFFFFF
[27201ms] DBG BUS RESET, gpio 0x35FBFFFF
[31715ms] DBG ---- SELECTION: 0
[31716ms] DBG ---- scsiStatusSEL()
[31717ms] DBG ------ scsiStatusATN()=1
[31717ms] DBG ------ PHYPHASE 0->3 atnFlag 128 dev phase 2 gpio 0x1BFADEFF compatMode 2
[31718ms] DBG ---- MESSAGE_OUT
[31718ms] DBG ------ scsiReadByte()
[31719ms] DBG ------ OUT: 0xC0 
[31719ms] DBG ------ scsiStatusATN()=0
[31720ms] DBG ------ PHYPHASE 3->2 atnFlag 0 dev phase 2 gpio 0x3BFED63F compatMode 2
[31721ms] DBG ------ scsiRead(6)
[31725ms] DBG BUS RESET, gpio 0x33FBF5FF
[31725ms] DBG ---- COMMAND: Unknown
[31726ms] DBG ------ OUT: 0x80 0x00 0x00 0x00 0x00 0x00 
[31726ms] DBG -- BUS_FREE
[80610ms] DBG -- BUS_BUSY
[80610ms] DBG -- BUS_FREE
[81130ms] DBG ---- SELECTION: 5
[81131ms] DBG ---- scsiStatusSEL()
[81131ms] DBG ------ scsiStatusATN()=1
[81132ms] DBG ------ PHYPHASE 2->3 atnFlag 128 dev phase 2 gpio 0x1BFADE3F compatMode 2
[81133ms] DBG ---- MESSAGE_OUT
[81133ms] DBG ------ scsiReadByte()
[81134ms] DBG ------ OUT: 0xC0 
[81134ms] DBG ------ scsiStatusATN()=0
[81134ms] DBG ------ PHYPHASE 3->2 atnFlag 0 dev phase 2 gpio 0x3BFED63F compatMode 2
[81135ms] DBG ------ scsiRead(6)
[81140ms] DBG BUS RESET, gpio 0x33FFF5FF
[81140ms] DBG ---- COMMAND: Unknown
[81140ms] DBG ------ OUT: 0x80 0xFF 0xFF 0xFF 0xFF 0xFF 
[81141ms] DBG -- BUS_FREE

@Kurist2010
Copy link
Author

For reference, if you start MS-DOS 6.2 from the FD after checking the BIOS, you can access SCSI from the DOS kernel. There is no problem with inquiries at this time. Also, the SCSI device is not recognized by his BIOS, so I can't use it without a device driver.

This is the continuation of the above log.

[128471ms] DBG -- BUS_BUSY
[128480ms] DBG -- BUS_FREE
[128481ms] DBG -- BUS_BUSY
[128481ms] DBG -- BUS_FREE
[131083ms] DBG -- BUS_BUSY
[131084ms] DBG -- BUS_FREE
[131603ms] DBG -- BUS_BUSY
[131603ms] DBG -- BUS_FREE
[141071ms] DBG ---- SELECTION: 0
[141072ms] DBG ---- scsiStatusSEL()
[141073ms] DBG ------ scsiStatusATN()=1
[141073ms] DBG ------ PHYPHASE 2->3 atnFlag 128 dev phase 2 gpio 0x1BFADFF7 compatMode 2
[141074ms] DBG ---- MESSAGE_OUT
[141075ms] DBG ------ scsiReadByte()
[141075ms] DBG ------ OUT: 0x80 
[141075ms] DBG ------ scsiStatusATN()=0
[141076ms] DBG ------ PHYPHASE 3->2 atnFlag 0 dev phase 2 gpio 0x3BFBD77F compatMode 2
[141077ms] DBG ------ scsiRead(6)
[141077ms] DBG ---- COMMAND: Inquiry
[141077ms] DBG ------ OUT: 0x12 0x00 0x00 0x00 0x24 0x00 
[141078ms] DBG ---- DATA_IN
[141078ms] DBG ------ scsiStatusATN()=0
[141079ms] DBG ------ PHYPHASE 2->4 atnFlag 0 dev phase 4 gpio 0x3BFFF77F compatMode 2
[141080ms] DBG ---- Total IN: 36 OUT: 0 CHECKSUM: 565
[141081ms] DBG ---- STATUS: 0 GOOD
[141097ms] DBG ------ scsiStatusATN()=0
[141097ms] DBG ------ PHYPHASE 4->6 atnFlag 0 dev phase 6 gpio 0x3BFFEFFF compatMode 2
[141098ms] DBG ---- MESSAGE_IN
[141098ms] DBG ------ scsiStatusATN()=0
[141099ms] DBG ------ PHYPHASE 6->7 atnFlag 0 dev phase 7 gpio 0x3BFBE7FF compatMode 2
[141100ms] DBG ------ IN: 0x00 
[141100ms] DBG ---- scsiEnterBusFree()
[141101ms] DBG -- BUS_FREE
[143175ms] DBG ---- SELECTION: 5
[143176ms] DBG ---- scsiStatusSEL()
[143176ms] DBG ------ scsiStatusATN()=1
[143177ms] DBG ------ PHYPHASE -1->3 atnFlag 128 dev phase 2 gpio 0x1BFBDF7F compatMode 2
[143178ms] DBG ---- MESSAGE_OUT
[143178ms] DBG ------ scsiReadByte()
[143179ms] DBG ------ OUT: 0x80 
[143179ms] DBG ------ scsiStatusATN()=0
[143179ms] DBG ------ PHYPHASE 3->2 atnFlag 0 dev phase 2 gpio 0x3BFED77F compatMode 2
[143180ms] DBG ------ scsiRead(6)
[143181ms] DBG ---- COMMAND: Inquiry
[143181ms] DBG ------ OUT: 0x12 0x00 0x00 0x00 0x24 0x00 
[143182ms] DBG ---- DATA_IN
[143182ms] DBG ------ scsiStatusATN()=0
[143182ms] DBG ------ PHYPHASE 2->4 atnFlag 0 dev phase 4 gpio 0x3BFBF77F compatMode 2
[143184ms] DBG ---- Total IN: 36 OUT: 0 CHECKSUM: 565
[143184ms] DBG ---- STATUS: 0 GOOD
[143197ms] DBG ------ scsiStatusATN()=0
[143198ms] DBG ------ PHYPHASE 4->6 atnFlag 0 dev phase 6 gpio 0x3BFFEFFF compatMode 2
[143199ms] DBG ---- MESSAGE_IN
[143199ms] DBG ------ scsiStatusATN()=0
[143199ms] DBG ------ PHYPHASE 6->7 atnFlag 0 dev phase 7 gpio 0x3BFBE7FF compatMode 2
[143200ms] DBG ------ IN: 0x00 
[143201ms] DBG ---- scsiEnterBusFree()
[143201ms] DBG -- BUS_FREE
[143201ms] DBG -- BUS_BUSY
[143203ms] DBG -- BUS_FREE

@aperezbios
Copy link
Collaborator

@Kurist2010 does this still happen with recent versions of the firmware, or is this resolved.

@Kurist2010
Copy link
Author

The issue was not resolved in the 2023-10-31 version.
Not confirmed in the 2023-11-27 version.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants