USBDriver ZeroPain & Debugger DataAbort

For some months I have been having occasional Data Aborts that appear to come from the Debugger module. These puzzled me, particularly as many seemed to be when the machine was idle. I then realised that there was an associated ZeroPain log, from the USBDriver module. My current theory is that the ZeroPain module calls the Debugger to produce some of its output, but that Data Aborts.

I would be grateful for any suggestions about how I can narrow this problem down – maybe it has even been fixed in the Development release. So far I have been unable to convert the code offsets into lines in the source for either USBDriver or Debugger.

One option would be to try the latest 5.27 ROM, but I am reluctant to do that on my main machine at the moment – and anyway it only happens occasionally (roughly once per week).

Summary

ZeroPain in USBDriver + &63c0 LDR R2,[R1,#68]! when r1=0
Data Abort in Debugger + &F650 STR R3,[R6,#288] when r6=0

Environment

Machine: Titanium
RISC OS 5.24 (16 Apr 2018)
USBDriver 1.28 (17 Mar 2018)
Debugger 2.02 (25 Feb 2018)
ZeroPain 0.09 (01 Dec 2018)

Example ZeroPain

Time: Sat Feb  1 19:41:10 2020
Location: Offset 000063c0 in module USBDriver
Current Wimp task: ShareFS
Last app to start: <NewsHound$Dir>.!Runimage
---
R0  = 2002828c R1  = 00000000 R2  = 00000000 R3  = 0000000c
R4  = 36107a00 R5  = 20020114 R6  = 36107a3c R7  = 00000002
R8  = 00000000 R9  = 00000000 R10 = 3610021c R11 = 36101f54
R12 = 00000000 R13 = 36101f2c R14 = fc1d6670 R15 = fc1d66c4
DFAR = 00000044  Mode SVC32  Flags nZCv if   PSR = 60000113
---
fc1d667c : e3590000 : CMP     R9,#0
fc1d6680 : 1a000012 : BNE     &FC1D66D0
fc1d6684 : e5952004 : LDR     R2,[R5,#4]
fc1d6688 : e5920000 : LDR     R0,[R2,#0]
fc1d668c : e5903030 : LDR     R3,[R0,#48]
fc1d6690 : e3530000 : CMP     R3,#0
fc1d6694 : 11a01006 : MOVNE   R1,R6
fc1d6698 : 11a0e00f : MOVNE   R14,PC
fc1d669c : 1593f010 : LDRNE   PC,[R3,#16]
fc1d66a0 : e5d41040 : LDRB    R1,[R4,#64]
fc1d66a4 : e3c12010 : BIC     R2,R1,#&10         ; =16
fc1d66a8 : e5c42040 : STRB    R2,[R4,#64]
fc1d66ac : ea000001 : B       &FC1D66B8
fc1d66b0 : e3590000 : CMP     R9,#0
fc1d66b4 : 1a000005 : BNE     &FC1D66D0
fc1d66b8 : e5951014 : LDR     R1,[R5,#20]
fc1d66bc * e5b12044 * LDR     R2,[R1,#68]!
fc1d66c0 : e3520000 : CMP     R2,#0
fc1d66c4 : 02851014 : ADDEQ   R1,R5,#&14         ; =20
fc1d66c8 : e5852014 : STR     R2,[R5,#20]
fc1d66cc : 05851018 : STREQ   R1,[R5,#24]
fc1d66d0 : e5952004 : LDR     R2,[R5,#4]
fc1d66d4 : e5951008 : LDR     R1,[R5,#8]
fc1d66d8 : e5923000 : LDR     R3,[R2,#0]
fc1d66dc : e5912000 : LDR     R2,[R1,#0]
fc1d66e0 : e5d20003 : LDRB    R0,[R2,#3]
fc1d66e4 : e3a02001 : MOV     R2,#1
fc1d66e8 : e2000003 : AND     R0,R0,#3
fc1d66ec : e0831100 : ADD     R1,R3,R0,LSL #2
fc1d66f0 : e2810f91 : ADD     R0,R1,#&0244       ; =580
fc1d66f4 : e5903000 : LDR     R3,[R0,#0]
fc1d66f8 : e2831001 : ADD     R1,R3,#1

I would have expected more!

Example DataAbort

19:41:10.86 ** WimpError ** from unknown task
  Error  : &80000002
  Message: Internal error: abort on data transfer at &FC1C7778
19:41:11 ZeroPain: 1 new log file entry
---
Address &FC1C7778 in Module   Debugger            @ &FC1B8128 + &F650
Register dump (at &20082090) is:
pc  = &FC1C7778  Flags=&80000113=Nzcv if  Mode=SVC 32 bit
r0  = &00000001 : .... :          1
r1  = &00000001 : .... :          1
r2  = &20EC07C4 : Ä.ì  :  552339396 => &FA2056B0 : °V ú : 4196423344
r3  = &FA2056B0 : °V ú : 4196423344 => &FC150D8C : …..ü : 4229238156
r4  = &361019E4 : ä..6 :  907024868 => &FA2055DC : ÜU ú : 4196423132
r5  = &FA205658 : XV ú : 4196423256 => &FC150DF4 : ô..ü : 4229238260
r6  = &00000000 : .... :          0
r7  = &0000000B : .... :         11
r8  = &00000001 : .... :          1
r9  = &FA205650 : PV ú : 4196423248 => &FA2056B0 : °V ú : 4196423344
r10 = &200821E4 : ä!.  :  537403876 => &00000000 : .... : 0
r11 = &00000001 : .... :          1
r12 = &00005650 : PV.. :      22096 => &00000000 : .... : 0
r13 = &36101960 : `..6 :  907024736 => &FA2056B0 : °V ú : 4196423344
r14 = &00008000 : .€.. :      32768
---
Code around address is:
FC1C7740 : E28DD008 : .Йâ : ADD     R13,R13,#8
FC1C7744 : E35B0000 : ..[ã : CMP     R11,#0
FC1C7748 : 0A000053 : S... : BEQ     &FC1C789C
FC1C774C : E357000B : ..Wã : CMP     R7,#&0B            ; =11
FC1C7750 : 1A000051 : Q... : BNE     &FC1C789C
FC1C7754 : E24DD008 : .ÐMâ : SUB     R13,R13,#8
FC1C7758 : E1A02009 : .  á : MOV     R2,R9
FC1C775C : E1A01004 : .. á : MOV     R1,R4
FC1C7760 : E1A0000D : .. á : MOV     R0,R13
FC1C7764 : EBFFF9F4 : ôù.ë : BL      &FC1C5F3C
FC1C7768 : E59D3000 : .0‡å : LDR     R3,[R13,#0]
FC1C776C : E5DD1004 : ..Ýå : LDRB    R1,[R13,#4]
FC1C7770 > E5863120 >  1ŷå : STR     R3,[R6,#288]
FC1C7774 : E3510000 : ..Qã : CMP     R1,#0
FC1C7778 : 0A000046 : F... : BEQ     &FC1C7898
FC1C777C : E59D0000 : ..‡å : LDR     R0,[R13,#0]

The USBDriver Pain looks familiar, this from about 3 years ago.

I have not seen it recently with Dev builds on my Titanium, which may only mean an “offending” USB device has not been used.

The Dev USBDriver is 1.29 (19 May 2018).

@David: Thanks – I had not looked that far back. But it certainly looks an indentical ZeroPain in USBDriver to mine. I will try to do some digging in USBDriver.

I have not seen it recently with Dev builds on my Titanium,

I have now! I was not using the machine, I saw the ZeroPain log pop up out of the corner of my eye!

“Current Wimp task: ShareFS”!

*FX0
RISC OS 5.27 (31 Jan 2020)
*Help USBDriver
Module is: USBDriver       1.29 (19 May 2018)
*Help Debugger
==> Help on keyword Debugger
Module is: Debugger        2.06 (28 Dec 2019)

Time: Sun Feb  2 14:54:31 2020
Location: Offset 0000645c in module USBDriver
Current Wimp task: ShareFS
Last app to start: amu -E  install COMPONENT=ABRelease TARGET=ABRelease INSTDIR=ADFS::ROOL.$.ROOL.DiscDev.RiscOS.Install.ROOL.Disc.Autobuild

R0  = 2005a64c R1  = 00000000 R2  = 00000000 R3  = 00000034
R4  = 3619f600 R5  = 20052214 R6  = 3619f63c R7  = 00000002
R8  = 00000000 R9  = 00000000 R10 = 3610021c R11 = 36101f54
R12 = 00000000 R13 = 36101f2c R14 = fc1dfca8 R15 = fc1dfcfc
DFAR = 00000044  Mode SVC32  Flags nZCv if   PSR = 60000113

fc1dfcb4 : e3590000 : CMP     R9,#0
fc1dfcb8 : 1a000012 : BNE     &FC1DFD08
fc1dfcbc : e5952004 : LDR     R2,[R5,#4]
fc1dfcc0 : e5920000 : LDR     R0,[R2,#0]
fc1dfcc4 : e5903030 : LDR     R3,[R0,#48]
fc1dfcc8 : e3530000 : CMP     R3,#0
fc1dfccc : 11a01006 : MOVNE   R1,R6
fc1dfcd0 : 11a0e00f : MOVNE   R14,PC
fc1dfcd4 : 1593f010 : LDRNE   PC,[R3,#16]
fc1dfcd8 : e5d41040 : LDRB    R1,[R4,#64]
fc1dfcdc : e3c12010 : BIC     R2,R1,#&10         ; =16
fc1dfce0 : e5c42040 : STRB    R2,[R4,#64]
fc1dfce4 : ea000001 : B       &FC1DFCF0
fc1dfce8 : e3590000 : CMP     R9,#0
fc1dfcec : 1a000005 : BNE     &FC1DFD08
fc1dfcf0 : e5951014 : LDR     R1,[R5,#20]
fc1dfcf4 * e5b12044 * LDR     R2,[R1,#68]!
fc1dfcf8 : e3520000 : CMP     R2,#0
fc1dfcfc : 02851014 : ADDEQ   R1,R5,#&14         ; =20
fc1dfd00 : e5852014 : STR     R2,[R5,#20]
fc1dfd04 : 05851018 : STREQ   R1,[R5,#24]
fc1dfd08 : e5952004 : LDR     R2,[R5,#4]
fc1dfd0c : e5951008 : LDR     R1,[R5,#8]
fc1dfd10 : e5923000 : LDR     R3,[R2,#0]
fc1dfd14 : e5912000 : LDR     R2,[R1,#0]
fc1dfd18 : e5d20003 : LDRB    R0,[R2,#3]
fc1dfd1c : e3a02001 : MOV     R2,#1
fc1dfd20 : e2000003 : AND     R0,R0,#3
fc1dfd24 : e0831100 : ADD     R1,R3,R0,LSL #2
fc1dfd28 : e2810f91 : ADD     R0,R1,#&0244       ; =580
fc1dfd2c : e5903000 : LDR     R3,[R0,#0]
fc1dfd30 : e2831001 : ADD     R1,R3,#1

--------------------------------------------------------------------------------

*where
Address &FC1D0C80 is at offset &0000F9B8 in module 'Debugger'
*showregs
Register dump (stored at &2006A210) is:
R0  = 00000001 R1  = 00000001 R2  = 2049EC1C R3  = 00000000
R4  = 361019E4 R5  = FA207CF0 R6  = 00000000 R7  = 0000000B
R8  = 00000001 R9  = FA207CE8 R10 = 2006A370 R11 = 00000001
R12 = 00007CE8 R13 = 36101960 R14 = 00008000 R15 = FC1D0C80
Mode SVC32 flags set: NzcvqjggggeAift        PSR = 80000113
*MemoryI PC-20 +40
FC1D0C60 : . †· : E1A02009 : MOV     R2,R9
FC1D0C64 : ..†· : E1A01004 : MOV     R1,R4
FC1D0C68 : ..†· : E1A0000D : MOV     R0,R13
FC1D0C6C : ı˘ˇÎ : EBFFF9F5 : BL      &FC1CF448
FC1D0C70 : .0ùÂ : E59D3000 : LDR     R3,[R13,#0]
FC1D0C74 : ..›Â : E5DD1004 : LDRB    R1,[R13,#4]
FC1D0C78 :  1ÜÂ : E5863120 : STR     R3,[R6,#288]
FC1D0C7C : ..Q„ : E3510000 : CMP     R1,#0
FC1D0C80 < F... : 0A000046 : BEQ     &FC1D0DA0
FC1D0C84 : ..ùÂ : E59D0000 : LDR     R0,[R13,#0]
FC1D0C88 : ..P„ : E3500000 : CMP     R0,#0
FC1D0C8C : 2... : 1A000032 : BNE     &FC1D0D5C
FC1D0C90 : .–M‚ : E24DD010 : SUB     R13,R13,#&10       ; =16
FC1D0C94 : . ùÂ : E59D2018 : LDR     R2,[R13,#24]
FC1D0C98 : ..†· : E1A01004 : MOV     R1,R4
FC1D0C9C : ..†· : E1A0000D : MOV     R0,R13
*

The USBDriver change from 1.28 to 1.29 is titled “Fix for alternate selection” which, like the associated description text, means nothing to me. There is nothing which indicates what visible user results it was to fix.

I have also tried to relate the error code offset to the source code, but it is a mixed asm/C module and I cannot see how to relate the two.

So, unless there are any more suggestions it seems that trying 5.27 is my only way … but that will not be until I can afford some downtime in a few weeks.

I suppose our last posts crossed in the post, but OS5.27 can have the issue.

This morning I changed back to an ex-Maplin Cerulian wireless keyboard and mouse pair and a few hours later up pops the fault. Now back on the keyboard and mouse in use when I said I had not seen the issue recently. See what happens next!

So RO5.27 is not the answer.
I have had ShareFS as the Current Wimp Task in the ZP log … but I have also had FullNames and FlowerBox Screensaver!
My keyboard is from my old Iyonix, with a wired USB mouse, although they are through a USB & VGA switch.

Your Debugger is newer than mine, which may explain why you do not see my DataAbort … but neither do you get any useful trace info in the ZP log!

but it is a mixed asm/C module and I cannot see how to relate the two.

Yes, sometimes don’t you just wish that function names were embedded in the binary?

What I’d do is look for something (hopefully) unique, like the R1,R5,#&14 in USBDriver. Load all the object files into Zap, switch to code mode, then get it to search for that, writing the results to a window. Hoping there aren’t too many, just work through them until you find the one with the matching code.
That’ll tell you what file to look at.

To narrow down to a line of code, build the file with the source output (-S) option, then load that into Zap and search again, the names/annotations will indicate where you are.

Note: For Zap, one could also read StrongEd.

an ex-Maplin Cerulian wireless keyboard

I trust it’s a mute blue, even if they did spell it wrongly…

My current theory is that the ZeroPain module calls the Debugger to produce some of its output, but that Data Aborts.

Correct. The ZeroPain output is mostly produced using the debugger exception dump facility.

This merge request should fix the Debugger crash.

but it is a mixed asm/C module and I cannot see how to relate the two.

Yes, sometimes don’t you just wish that function names were embedded in the binary?

They are, to a certain extent. There’s a symbol table after the ROM modules, which is how zero pain / debugger exception dumps are able to give you symbol names for the ROM. However the *Where command isn’t hooked up to it yet. And there should probably be some kind of programmatic interface too (probably incorporating a service call/vector, so things like SOManager can offer symbol lookup services for the binary formats they understand). Merge requests welcome! ;-)

Thanks Jeffrey: I will try to update to the new ROM when the new Debugger is included, in the hope it may give some clues as to the cause of the ZeroPain.

I am now running RO5.27 (06 Feb 2020) with the fixed debugger, and I can report that I have had a ZeroPain log in USBDriver +&645c with full details, and no DataAbort in Debugger (thanks Jeffrey).

However, Sprow thinks that it is not a problem in USBDriver, but elsewhere in the USB stack.
It might help to narrow this down if anyone else seeing a ZP log in USB Driver reports it here, with details of machine, OS version and USBDevices.

I have a persistent problem with USB on an ARMX6, running 5.25. When I switch to the ARMX6 on the KVM switch, and move the mouse immediately, the computer locks up. No response to mouse or keyboard. Sometimes (about 20% of times) switching away and back will get a response, more often I need to power off and on. Sometimes it will lock up with no mouse movement, though this is rare.

I don’t know whether this is relevant to this thread.

I don’t know of a way to get more information. If there is one, I would be happy to supply it.

Alan, this is a long shot, but if you have !DiscKnight [https://armclub.org.uk/products/discknight/]
it might be worth running a check/repair on the drive you’re booting from. I’ve found in the past that random problems can be due to corruption of the drive map.

I do have DiskKnight. The drive is an SSD. Is it safe/appropriate in this case?

I’ve run it in checking mode and it reports “disc is good”.

The drive is an SSD. Is it safe/appropriate in this case?

Yes (as you have already discovered).

I’ve run it in checking mode and it reports “disc is good”.

Well at least you’ve eliminated one potential source of trouble!

The drive is an SSD. Is it safe/appropriate in this case?

The underlying technology is not so relevant to the issue of checking the logical structure of the disc.

Spinning rust, SSD, or µSD – they all present a large number of sectors and tracks which comprise the “physical” structure.
The operating system then sets up maps and directories and where to put everything. This is the “logical” structure. DiscKnight checks the logical structure to make sure that it is correct, because clearly if two files think they are storing their data in the same place…it’s not good.

There is the additional complication that most physical Flash media will likely not have the blocks in actual order, unlike spinning rust. This is due to them being shuffled around as part of the wear levelling mechanism, however this behaviour is invisible to the operating system. It will return the data asked for regardless of where it is actually storing it (and you’ll only be able to find that out if you rip the NAND (?) chip out and wire it up to something to read it directly). So don’t sweat it.

Just know, that if SSD/Flash wear was to be any issue, there are a half dozen reasons why not to use a FileCore based filesystem; yet I would imagine more than a few of us have been using domestic quality SD cards in our machines for several years. They will fail eventually, but then so do traditional harddiscs.
Just have a worthy backup strategy and a means of sourcing a replacement so you can swap out broken media for good, restore, and keep on going…

Well at least you’ve eliminated one potential source of trouble!

Indeed. And since DiscKnight is fast, it’s worth performing periodic checks. Mine is “Saturday night” (to give me all of Sunday if the excrement hits the rotating aerator), after power failures, and after press-Reset-button if my little indicator shows there was a disc write in progress when the machine crashed.

Or, since it only takes a few seconds, why not now? <clicky-clicky>

---------------------------------------------
                Disc is good
---------------------------------------------

YES! :-)

It might help to narrow this down if anyone else seeing a ZP log in USB Driver reports it here, with details of machine, OS version and USBDevices.

Two more of USBDriver ZeroPain events happened today on the Titanium, the first in a week. For the second event I was not even in the same room as the Titanium. Suspicion (may) fall on wireless keyboard and mouse combo, listed as MOSART Semi. There is no change in USB device order before and after.

Time: Mon Feb 10 13:12:52 2020
Location: Offset 0000645c in module USBDriver
Current Wimp task: ShareFS
Last app to start: TaskWindow 410039C0 00000002  -ctrl

*fx0
RISC OS 5.27 (06 Feb 2020)
*USBDevices
No. Bus Dev Class Description
  1   1   0  9/ 0 Synopsys XHCI root hub
  2   1   1  9/ 0 SMSC USB 2.0 4-Port Hub
  3   1   2  9/ 0 Genesys Logic USB2.0 Hub
  4   1   3  0/ 0 SanDisk Cruzer Glide
  5   1   4  0/ 0 MOSART Semi. 2.4G Keyboard Mouse
  6   1   5  0/ 0 SanDisk Ultra
  7   2   0  9/ 0 Synopsys XHCI root hub
  8   2   1  9/ 0 SMSC USB 2.0 4-Port Hub
*
*USBDevInfo 5
USB release     : 0110
Device class    : 00
Device subclass : 00
Device protocol : 00
Max packet size : 08
Vendor ID       : 062A
Product ID      : 4101
Device ID       : 0312
# of configs    : 1
Manufacturer    : 'MOSART Semi.'
Product         : '2.4G Keyboard Mouse'
Serial number   : ''
Speed           : Full
*