hoglet67 / PiTubeDirect

Bare-metal Raspberry Pi project that attaches to the Acorn TUBE interface and emulates many BBC Micro Co Processors
GNU General Public License v3.0
187 stars 23 forks source link

RISC V Co Pro: Escape sometimes being reported when pressing RETURN #197

Closed mincebert closed 11 months ago

mincebert commented 11 months ago

I have this odd problem where Escape is being reported when I push RETURN in BASIC sometimes. Basically, I type in a line and then push Return and, very occasionally, I get Escape printed as if I'd pushed the ESCAPE key. It only happens when I push RETURN and not at some random point in the middle of the line, typing something else, or not pushing a key.

I haven't had this problem in any other co-processor than the RISC-V (or at least haven't noticed it) and I've had it going on since I started using it but wasn't sure I wasn't accidentally hitting ESCAPE somehow, but I'm pretty sure I've had it a few times when I definitely haven't been near ESCAPE. I also don't use the RISC-V processor outside BASIC enough to know if it's RVBASIC or the co processor itself.

It's possible I've got a faulty ESCAPE key but I haven't seen it anywhere else! Unfortunately. I’ve not found a pattern which triggers it yet.

This is on a Master with MOS 3.50, and internal IFEL level shifter board (not sure which version but bought in July 2022) and a Pi 3A+.

On StarDot, you said:

Can you try to gather some data on when it happens? For example, if you just sit there hitting return, does it ever happen? A screen shot would be helpful as there may be some clues.

I'll try these and see how I get on. Sorry this is so vague and anecdotal!

hoglet67 commented 11 months ago

If the Master was randomly generating an escape event, then this would happen in the middle of the line, not just when you press return. So I don't think that's happening.

I haven't seen this myself at all.

Is it possible it's a delayed escape from the previous line? i.e. does it correlate to the previous line being terminated by a genuine escape press?

I'll switch to MOS 3.50 and a Pi 3A+ and try to reproduce.

mincebert commented 11 months ago

I don't think I pushed ESCAPE on the previous line. I've pushing RETURN for a bit at the prompt in RVBASIC and not had one so far.

It's not very frequent and I'm still not convinced I'm not going mad but I thought I'd report it in case someone else has seen it. It's probably the sort of thing you should ignore and just use it (in the same configuration?) to see if you start seeing it, unless you have some leads!

hoglet67 commented 11 months ago

A couple more questions, so I can get my config as close as possible to yours:

mincebert commented 11 months ago

I'm normally in MODE 7, I would say (occasionally in MODE 1 or MODE 6).

Yes — the indigo alpha2 build and the 20230911 RVBASIC release. I'm usually working from ANFS off a PiEconetBridge.

hoglet67 commented 11 months ago

Sorry Robert, I've not managed to reproduce this yet.

I can't see any errors in the code, especially in handling the happy path (the non-escape case)

I'm wondering if this is another obscure tube data corruption bug?

The tube protocol for OSWORD0 terminated by a normal return looks like:

Co Pro: R2: &0A block
Host:   R2: &7F string &0D

And if it's terimanted by escape the &7F changes to &FF, and there is no string sent.

Co Pro: R2: &0A block
Host:   R2: &FF

So if the normal &7F somehow got corrupted to &FF (or anything with the MSB set), that might cause an issue like this. But then the tube protocol would be out of sync between the Co Pro and the Host, because the Host would still be trying to send the string, and the Co Pro would not be expecting it. This would normally result in a hang.

After this has happened, is everything working normally (apart from the bogus escape)? Or does the system hang or behave strangely.

Was the line you just typed in ignored?

The only way I can think of debugging this is to use the debugger and set some watchpoint on the R1/R2tube registers:

>> watchr ffffe4
>> watchr ffffec
>> watchw ffffec

Then a normal OSWORD0 call looks like:

Mem Wr watchpoint hit at fc138c : ffffec = 0a ( . )
Mem Wr watchpoint hit at fc138c : ffffec = ff ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 20 (   )
Mem Wr watchpoint hit at fc138c : ffffec = ff ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 07 ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 00 ( . )
Mem Rd watchpoint hit at fc1368 : ffffec = 7f ( . )
Mem Rd watchpoint hit at fc1368 : ffffec = 48 ( H )
Mem Rd watchpoint hit at fc1368 : ffffec = 45 ( E )
Mem Rd watchpoint hit at fc1368 : ffffec = 4c ( L )
Mem Rd watchpoint hit at fc1368 : ffffec = 4c ( L )
Mem Rd watchpoint hit at fc1368 : ffffec = 4f ( O )
Mem Rd watchpoint hit at fc1368 : ffffec = 0d ( . )

One that's terminated with a real escape is much more complicated, because it includes two "escape flag changed" interrupts and an osbyte call.

Mem Wr watchpoint hit at fc138c : ffffec = 0a ( . )
Mem Wr watchpoint hit at fc138c : ffffec = ff ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 20 (   )
Mem Wr watchpoint hit at fc138c : ffffec = ff ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 07 ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 00 ( . )
Mem Rd watchpoint hit at fc0ee0 : ffffe4 = ffffffc0 ( . )
Mem Rd watchpoint hit at fc1368 : ffffec = ff ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 04 ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 00 ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 7e ( ~ )
Mem Rd watchpoint hit at fc0ee0 : ffffe4 = ffffff80 ( . )
Mem Rd watchpoint hit at fc1368 : ffffec = ff ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 0a ( . )
Mem Wr watchpoint hit at fc138c : ffffec = ff ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 20 (   )
Mem Wr watchpoint hit at fc138c : ffffec = ff ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 07 ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 00 ( . )

Having a trace like this of the bogus escape would really help narrow this down.

Dave

mincebert commented 11 months ago

Thanks for the testing and reply... to answer your question about reliability: I don't have any problems with the machine in general with anything crashing at any point and I run with the PiTubeDirect enabled most of the time. When the Escape is printed upon RETURN, the machine continues working fine.

The only problem I get is sometimes, when I try changing copro type with *FX 151,230,n, it doesn't actually change and stays in the current processor. But the machine/PiTubeDirect doesn't hang and trying the same command again works. It's mildly annoying but I've never been bothered enough to investigate it.

I think it's probably worth me just connecting up something to log from the serial terminal all the time and I just use the machine normally and, if I get it again, I look at the output. We can then just park this issue unless I see it happen again and I'm confident I didn't push ESCAPE!

Is there a way to set the debug commands to autorun each time the PiTubeDirect starts up? That would makes thing considerably easier!

hoglet67 commented 11 months ago

Is there a way to set the debug commands to autorun each time the PiTubeDirect starts up? That would makes thing considerably easier!

Unfortunately not.

Dave

mincebert commented 11 months ago

I've got a terminal connected to the debug serial port and the commands I can paste in after I start it up each time.

I'll just use the BBC/PiTubeDirect as normal with this going on and grab a chunk of the logs and a screenshot, if it misbehaves again (which, of course, it hasn't!).

As an aside, I did have the problem where *FX 151,230,23 didn't take effect (although the 23 doesn't matter - it's selecting any copro) and nothing was logged (error or otherwise): it just didn't print "New copro ...". Entering it a second time worked fine, though.

hoglet67 commented 11 months ago

As an aside, I did have the problem where *FX 151,230,23 didn't take effect (although the 23 doesn't matter - it's selecting any copro) and nothing was logged (error or otherwise): it just didn't print "New copro ...". Entering it a second time worked fine, though.

FYI, That's something I have also seen occasionally, and it's not a new thing. I've seen it sporadically for a number of years. Again, it's been hard to reproduce!

mincebert commented 11 months ago

Here you go — I got one here... I did *TYPE RV-TEXT to list a file, pushed ESCAPE to stop it, then typed *. and got a spurious Escape.

Interestingly, it seems reproduceable — if I interrupt something like a *TYPE or a *DUMP with ESCAPE, I get an Escape on the next -command; if I enter a non -command first (say NEW), I then get an Escape on the next *-command or error message. For example:

>*TYPE RV-TEXT
...

Escape     <--- real Escape
>NEW
>LIST
>MINCE

Escape     <--- spurious Escape
>

Here's the tail of the PiTubeDirect debug with the watches set:

...
Mem Wr watchpoint hit at fc138c : ffffec = 07 ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 00 ( . )
Mem Rd watchpoint hit at fc1368 : ffffec = 7f ( . )
Mem Rd watchpoint hit at fc1368 : ffffec = 2a ( * )
Mem Rd watchpoint hit at fc1368 : ffffec = 54 ( T )
Mem Rd watchpoint hit at fc1368 : ffffec = 59 ( Y )
Mem Rd watchpoint hit at fc1368 : ffffec = 50 ( P )
Mem Rd watchpoint hit at fc1368 : ffffec = 45 ( E )
Mem Rd watchpoint hit at fc1368 : ffffec = 20 (   )
Mem Rd watchpoint hit at fc1368 : ffffec = 52 ( R )
Mem Rd watchpoint hit at fc1368 : ffffec = 56 ( V )
Mem Rd watchpoint hit at fc1368 : ffffec = 2d ( - )
Mem Rd watchpoint hit at fc1368 : ffffec = 54 ( T )
Mem Rd watchpoint hit at fc1368 : ffffec = 45 ( E )
Mem Rd watchpoint hit at fc1368 : ffffec = 58 ( X )
Mem Rd watchpoint hit at fc1368 : ffffec = 54 ( T )
Mem Rd watchpoint hit at fc1368 : ffffec = 0d ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 02 ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 54 ( T )
Mem Wr watchpoint hit at fc138c : ffffec = 59 ( Y )
Mem Wr watchpoint hit at fc138c : ffffec = 50 ( P )
Mem Wr watchpoint hit at fc138c : ffffec = 45 ( E )
Mem Wr watchpoint hit at fc138c : ffffec = 20 (   )
Mem Wr watchpoint hit at fc138c : ffffec = 52 ( R )
Mem Wr watchpoint hit at fc138c : ffffec = 56 ( V )
Mem Wr watchpoint hit at fc138c : ffffec = 2d ( - )
Mem Wr watchpoint hit at fc138c : ffffec = 54 ( T )
Mem Wr watchpoint hit at fc138c : ffffec = 45 ( E )
Mem Wr watchpoint hit at fc138c : ffffec = 58 ( X )
Mem Wr watchpoint hit at fc138c : ffffec = 54 ( T )
Mem Wr watchpoint hit at fc138c : ffffec = 0d ( . )
Mem Rd watchpoint hit at fc0ee0 : ffffe4 = ffffffc0 ( . )
Mem Rd watchpoint hit at fc0ee0 : ffffe4 = ffffff80 ( . )
Mem Rd watchpoint hit at fc1368 : ffffec = 00 ( . )
Mem Rd watchpoint hit at fc1368 : ffffec = 11 ( . )
Mem Rd watchpoint hit at fc1368 : ffffec = 45 ( E )
Mem Rd watchpoint hit at fc1368 : ffffec = 73 ( s )
Mem Rd watchpoint hit at fc1368 : ffffec = 63 ( c )
Mem Rd watchpoint hit at fc1368 : ffffec = 61 ( a )
Mem Rd watchpoint hit at fc1368 : ffffec = 70 ( p )
Mem Rd watchpoint hit at fc1368 : ffffec = 65 ( e )
Mem Rd watchpoint hit at fc1368 : ffffec = 00 ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 0a ( . )
Mem Wr watchpoint hit at fc138c : ffffec = ff ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 20 (   )
Mem Wr watchpoint hit at fc138c : ffffec = ff ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 07 ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 00 ( . )
Mem Rd watchpoint hit at fc1368 : ffffec = 7f ( . )
Mem Rd watchpoint hit at fc1368 : ffffec = 2a ( * )
Mem Rd watchpoint hit at fc1368 : ffffec = 2e ( . )
Mem Rd watchpoint hit at fc1368 : ffffec = 0d ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 04 ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 00 ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 7e ( ~ )
Mem Rd watchpoint hit at fc0ee0 : ffffe4 = ffffff80 ( . )
Mem Rd watchpoint hit at fc1368 : ffffec = 00 ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 0a ( . )
Mem Wr watchpoint hit at fc138c : ffffec = ff ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 20 (   )
Mem Wr watchpoint hit at fc138c : ffffec = ff ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 07 ( . )
Mem Wr watchpoint hit at fc138c : ffffec = 00 ( . )

And I've attached a copy of the screen at the time:

RV Escape screen

mincebert commented 11 months ago

Oh, and the problem doesn't occur when at the RISC-V copro NLE * prompt, only when in RVBASIC, so it might be a problem with that, not PiTubeDirect.

hoglet67 commented 11 months ago

That's great work Robert, and makes it very clear what's going on.

The bug I think is in the BBC Basic escape handler: https://github.com/hoglet67/BBCSDL/blob/master/console/riscv/crt0.s#L18

# Called with a0 bit 6 being the escape flag
escape_handler:
   andi    a0, a0, 64
   beqz    a0, done
   la      a0, flags
   lw      t0, (a0)
   ori     t0, t0, 0x80
   sw      t0, (a0)
done:
   ret

This is meant to propagate the escape flag into bit 7 of BBC Basic's flags variable. The bug is I only considered the case of propagating the setting of the escape flag. I also need to propagate the clearing of the escape flag.

i.e. I never considered the case where the OSBYTE doing the clearing was done by the host itself, as I think is the case when *TYPE is interrupted.

At least, I think that's what's happing from your trace.

I'll try to fix this later today.

hoglet67 commented 11 months ago

This is now fixed in: https://github.com/hoglet67/BBCSDL/commit/eff2e1ca

I'm planning an alpha3 release over the weekend, so it will be included in that.