DEV Community: Charles Anthony

2024-02-17 Multics Hang at 'CPU Add' During Boot, Part 3

Charles Anthony — Sun, 18 Feb 2024 01:55:18 +0000

2: 00043:000453 0 000006237120 (LDAQ PR0|6,N*) 000000 620(0) 0 0 0 05
2: 00043:000454 0 400132057120 (SSCR PR4|132,N*) 000120 237(0) 0 0 0 00
2: 00043:000455 0 700044710120 (TRA PR7|44,N*) 000000 057(0) 0 0 0 10
2: 00041:030325 0 600000373100 (EPBP7 PR6|0) 030325 710(0) 0 0 0 00
2: 030326 320050710200 (TRA 320050) 000000 373(0) 1 0 0 00
2: 320050 000346754204 (STI 000346,IC) 320050 710(0) 0 1 0 00

43:455

Segment 43 is bound_priv_1, offset 455 is privileged_mode_ut:455

" " " " " " " " " " " " " " " " " " " " " " " " " " " " " " " " " " " "
"
"       rscr and sscr are called in order to execute the rscr and sscr
"               instructions, respectively. "value" is the output or input argument
"               for these instructions as specified in the processor manual,
"               respectively.

rscr:
        lda     ap|2,*          port number in A
        als     10-3            multiply by 128
        adla    ap|4,*          add in scr_input
        als     3               port*1024 + scr_input*8
        rscr    scas$,al                read controller regs
        staq    ap|6,*          Output value.
        short_return

The return from the rscr call went off into lala land....

Added a instruction trace of CPU C. 17K instructions in, it executing the init_processor code as a result of a connect interrupt. The connect interrupt vector is re-vectored to init_processor (instead of the expected connect_handler code) because the bootload CPU is trying to setup for starting CPU D. As part of that setup, it should signal CPUs B and C that startup code is executing and the need to "stand very still" because vectors are being redirected. Examination of the trace shows that CPU C never received that signal, and was continuing on in the idle process. That process includes a self-connect step. When that connect happened, the init_processor code was executed instead of connect_handler. The init_processor code checks the CPU configuration and sees that the CPU thinks it is CPU C instead of the expected CPU D and signals the boot load processor that there was a configuration error. It is unclear why the bootload CPU is not responding to that signal, but that is not relevant to the problem: why did CPU C not get signaled to "stand very still" while CPU D was being setup for initialization.

I add some code to track the start_cpu code, but that caused the simulator to stop hanging and boot normally; I took that code back out and it still won't hang, so now I have no way of testing the bug.

2024-02-17 Multics Hang at 'CPU Add' During Boot, Part 2

Charles Anthony — Sat, 17 Feb 2024 17:58:49 +0000

A user reported a repeatable hang on a Raspberry Pi; I fired up my Pi 4 Model B and ran the latest simulator (15e7721dd6a2c58b5d3eea4e0428c3e71a9004ec) with Quickstart 12.8, modified the Multics config, adding:

cpu -tag b -port 6 -state on -type dps8 -model 70. -cache 8. 
cpu -tag c -port 5 -state on -type dps8 -model 70. -cache 8. 
cpu -tag d -port 5 -state on -type dps8 -model 70 -cache 8. 
cpu -tag e -port 4 -state on -type dps8 -model 70 -cache 8.

This adds CPUs B, C, D, and E to the configuration, with state set to on, they will be started during boot.

 ./dps8 MR12.8_boot.ini 
DPS8/M simulator X3.0.1+16 (64-bit)
  Commit: 15e7721dd6a2c58b5d3eea4e0428c3e71a9004ec

bce (boot) 0817.2: M-> [auto-input] boot star

0817.9  CPU A: Model #: DPS 8/SIM M; Serial #: 0; Ship date: 240215; PROM Layout Version: 2; 
          Simulator Release: X3.0.1 (2024-02-15); Build Number: <None>;  
          Build Arch: aarch64; Build OS: Linux; 
          Target Arch: AArch64/ARM64/64-bit; Target OS: GNU/Linux.
CPU B thread created.
0817.9  start_cpu: Added CPU B.
CPU C thread created.
0817.9  start_cpu: Added CPU C.

and it hangs...

Interestingly, this is not the symptom seen by the issue reporter, there hang is at the "CPU B thread created." message; they never see "0817.9 start_cpu: Added CPU B.".
(The "thread created" message is from the simulator; the messages starting with a time code are from Multics.)

$ gdb dps8 16473
(gdb) p/o cpus[0].PPR
$1 = {PRR = 0, PSR = 034, P = 01, IC = 02427}
(gdb) p/o cpus[1].PPR
$2 = {PRR = 0, PSR = 034, P = 01, IC = 02427}
(gdb) p/o cpus[2].PPR
$3 = {PRR = 0, PSR = 041, P = 01, IC = 0320127}
(gdb) p/o cpus[3].PPR
$4 = {PRR = 0, PSR = 0, P = 0, IC = 0}

CPUs A and B are executing 34:2427

bound_interceptors                 34  (0, 0, 0) read execute privileged encacheable wired

Component                            Text        Int-Stat       Symbol
                                 Start Length  Start Length  Start Length

fim                                  0   2210      0      0    100    266
wired_fim                         2210    332      0      0    366    230

34:2427 is offset 2427-2210 --> 217 in wired_fim:

                                   378  " " " " " " " " " " " " " " " " " " " " " " " " " " " " " " " " " " " "
                                   379  "
                                   380  "       START_WAIT - Wait until new CPU has started up.
                                   381  "
                                   382  "
                                   383  " " " " " " " " " " " " " " " " " " " " " " " " " " " " " " " " " " " "
                                   384
    000205                         385  start_wait:
    000205  aa   000001 3352 07    386          lca     1,dl            all ones in A
    000206  4a  4 00016 6753 20    387          era     prds$processor_pattern  turn off bit for this CPU
    000207  4a  4 00030 3553 20    388          ansa    scs$processor_start_wait  check ourselves off
                                   389
    000210  4a  4 00074 3737 20    390          eppsb   prds$           push a frame onto the prds
    000211  0a   000325 2272 00    391          ldx7    push            ..
    000212  4a  4 00076 7003 20    392          tsx0    fim_util$push_stack_32  ..
                                   393
    000213  aa  6 00050 3503 00    394          eppap   notify_regs     ap -> place to copy conditions
    000214  4a  4 00100 7003 20    395          tsx0    fim_util$copy_mc        copy the conditions into stack
                                   396
    000215  4a  4 00102 7003 20    397          tsx0    fim_util$set_mask       uninhibit to prevent lockups
    000216                         398          inhibit off     <-><-><-><-><-><-><-><-><-><-><-><->
                                   399
    000216  4a  4 00072 2341 20    400          szn     scs$connect_lock        test connect lock
    000217  0a   000223 6000 00    401          tze     *+4             wait until it is cleared
    000220  aa   000110 7770 00    402          llr     72
    000221  aa   000110 7770 00    403          llr     72
    000222  0a   000216 7100 00    404          tra     *-4

The start CPU code holds connect_lock during new CPU startup; I am confused as to why both CPUs A (cpus[0]) and B (cpus[1]) are both in start_wait, but that may just be my not understanding how the running not-bootload CPUs work during CPU add.

CPU C (the newly added CPU) is at 320127

This seems to be

    000125  aa   000002 2352 07    158  swerr:  lda     rcerr_addcpu_bad_switches,dl
    000126  aa   000272 7552 04    159          sta     wait_flag-*,ic  set it for start_cpu
    000127  aa   077777 6372 03    160  swerr_lp:       ldt     =o77777,du      prevent timer runout faults
    000130  aa   000270 2352 04    161          lda     wait_flag-*,ic  has start_cpu given use a green lite?
    000131  aa   000043 6042 04    162          tmi     nogo-*,ic               no, bad switches go to DIS
    000132  aa   000002 1152 07    163          cmpa    rcerr_addcpu_bad_switches,dl is start_cpu still thinking about it?
    000133  aa   777774 6002 04    164          tze     swerr_lp-*,ic   yes, go through another loop

Which makes no sense; the bootload CPU issued the CPU started message, which means CPU C had long ago passed the switch tests. Also, this is the same symptom that I was seeing yesterday.

Doing a instruction trace of CPU C:

2: 00041:030315 0 700026764161 (LPRP4 PR7|26,*AU) 000034 545(0) 1 0 0 00
2: 00041:030316 0 200001710100 (TRA PR2|1) 000000 764(0) 0 0 0 01
2: 00043:001033 0 000446710000 (TRA 000446) 000001 710(0) 1 0 0 00
2: 00043:000446 0 000002235120 (LDA PR0|2,N*) 000446 710(0) 0 0 0 00
2: 00043:000447 0 000007735000 (ALS 000007) 000214 235(0) 0 0 0 00
2: 00043:000450 0 000004035120 (ADLA PR0|4,N*) 000007 735(0) 0 0 0 00
2: 00043:000451 0 000003735000 (ALS 000003) 002473 035(0) 0 0 0 00
2: 00043:000452 0 000000620005 (EAX0 000000,AL) 000003 735(0) 0 0 0 00
2: 00043:000453 0 000006237120 (LDAQ PR0|6,N*) 000000 620(0) 0 0 0 05
2: 00043:000454 0 400132057120 (SSCR PR4|132,N*) 000120 237(0) 0 0 0 00
2: 00043:000455 0 700044710120 (TRA PR7|44,N*) 000000 057(0) 0 0 0 10
2: 00041:030325 0 600000373100 (EPBP7 PR6|0) 030325 710(0) 0 0 0 00
2: 030326 320050710200 (TRA 320050) 000000 373(0) 1 0 0 00
2: 320050 000346754204 (STI 000346,IC) 320050 710(0) 0 1 0 00
2: 320051 000345235204 (LDA 000345,IC) 000346 754(0) 0 1 0 04
2: 320052 000020315207 (CANA 000020,DL) 000345 235(0) 0 1 0 04
2: 320053 000120600204 (TZE 000120,IC) 000020 315(0) 0 1 0 07
2: 320054 320372674202 (LCPR 320372,QU) 000120 600(0) 0 1 0 04
2: 320055 000000623200 (EAX3 000000) 320372 674(0) 0 1 0 02
2: 320056 000000627200 (EAX7 000000) 000000 623(0) 0 1 0 00

76K instructions in, it decides it wants to start executing init_processor code in ABS.

2024-02-17 Multics Hang at 'CPU Add' During Boot, Part 1

Charles Anthony — Sat, 17 Feb 2024 15:35:40 +0000

Multics implementation has a subtle but problematic assumption: that all of the CPU's run about the same rate.

For the DPS8/M simulator's running of CPUs in individual threads, this can be problematic. For example, during boot the bootload CPU will start the additional configured CPUs something like thus:

Signal all other running CPUs to idle
Set up fault vectors to direct interrupted CPU to start-up code
Clear "I am running flag"
Interrupt new CPU 
Count to 5000
Check "I am running flag", if not set, the new CPU failed to start
...

and

interrupt_handler:
Check CPU configuration; if ok, set "I am running flag"
Continue with initialization code...

Because the CPU threads run at different rates, and because the newly started thread has more initial overhead (thread creation time, cache misses), it can be the case that it does not reach "set flag" before the bootload processor has counted to 5000, leading to Multics chaos where Multics believes that the added processor is not running, yet that processor is in the scheduler code looking for work to do.

The correct solution is to load balance the CPU threads so that they work at the same pace, but that is a hard problem.

The short term solution was to add "stall points"; the simulator CPU threads watch specified instructions in the Multics executable and suspend themselves for a short time before executing the instruction, allowing other CPU threads time to catch up. For the above case, a stall point is set at the start of the "Count to 5000" code; the causes the boot CPU thread to suspend, giving the new CPU thread time to get to the "set the flag" state before the "count to 5000" loop runs.

This problem is believed to be only in the Multics CPU start up code, whereas the rest of Multics follows much more rigorous synchronization practices. The code that handles CPU start up was reviewed and potential race conditions identified, and stall points added to the simulator configuration to forestall problems.

This has fixed the problem for nearly all cases, but a few corner cases remain. Heavily loaded systems may experience wait times exceeding the specified stall times, and very low-end systems (fewer host CPUs then the simulator CPU threads or insufficient cache for example) have been know to encounter occasional intermittent problems.

However, a reliable fail scenario was recently characterized, and tweaking stall point settings has proven ineffective, prompting a deeper examination into the issue.

2024-02-07 ZIP for CP/M

Charles Anthony — Wed, 07 Feb 2024 22:07:41 +0000

Using "The Programmer's CP/M Handbook" by Andy Johnson-Laird.

Using CP/M v2 from [https://schorn.ch/altair.html].

I suspect that my ZIP should be putting buffers and stacks at the end of memory, but I need to better understand CP/M's memory layout and the implications of overwriting CCP, so I am going to leave that alone for the nonce.

Copying code from [https://github.com/dimitrit/figforth].

Renaming "DISKI/O" to "DSKI/O" due to name collision with "DISPLAY".

Transcribing and translating discio.asm from diitrit/figforth

2024-01-31 Coverage testing

Charles Anthony — Wed, 07 Feb 2024 15:28:03 +0000

Coverage testing is completed.

Shortcomings in the coverage testing:

_patch has code to do a restart during compilation; it seems to be broken, and so is not tested.
tick has code to search current if the word is not in context; I was unable to devise a test for that case.
*ELSE has code for page boundary crossing that is not tested.
*LOOP has code for page boundary crossing that is not tested.
D* has code for propagating a negation carry that is not tested.
D/MOD has code for negative divisors and dividends that is not tested.

2024-01-30 ZIP Coverage testing

Charles Anthony — Wed, 07 Feb 2024 15:26:25 +0000

The TIL book refers to “PAD” but does not define it. I implemented what I thought it did, but the only code that calls it is “.R” and that is behaving weirdly. Looking at the code for “.R” I am completely baffled by it. I think it is trying to do stack arithmetic to measure the length of the string on the stack, but the code (at least as transcribed in the book) doesn’t do that. Either my implementation of “<#”, “#S”, et al is screwy; or there is a really annoying error in the book’s definition of “.R”.

Not having “.R” breaks “DUMP” and “ADUMP”.

Maybe the next step is to rummage through FIG-FORTH sources and see if I can find an equivalent word (that works) and translate it to ZIL.

2024-01-29 Debugging ZIP

Charles Anthony — Wed, 07 Feb 2024 04:24:50 +0000

I added some code to the OpenSIMH Altairz80 simulator to track memory access; for each byte of memory, it tracks if the byte was executed by the CPU, if the byte was an instruction operand, if the byte was read and if it was written. At the end of execution, the simulator writes the data out to a file. I then wrote a program that merged that data into the ZIP assembly listing, giving me a coverage map; I can see exactly which bits of code was executed in a run, and which were skipped.

As an example:

---- 00cf                          
  X  00cf 3a 00 01              _patch: ld      a,(s_mode)      ; get mode variable
  X  00d2 a7                            and     a               ; is it zero (execute)?
  X  00d3 ca 11 00                      jp      z,_abort        ; if so, restart
     00d6 d5                            push    de              ; else save message address
     00d7 2a 0e 01                      ld      hl,(s_current)  ; get vocabulary address
     00da 5e                            ld      e,(hl)          ; it points to the latest
     00db 23                            inc     hl              ;   entry, which was aborted

The “X”es indicate that the first 3 lines of “_patch” were executed, but it always took the “wasn’t compiling” path.

And for the case of compiled words:

R    0744 01 ..                 db      1,"'  "
R    0748 b2 06         L_0004: dw      L_0003-4
R    074a 49 00         tick:   dw      p_colon
R    074c 92 0c                 dw      aspace  ; get the seperator
R    074e ca 13                 dw      token   ; scan the next token
R    0750 11 0e                 dw      context ; contect address
R    0752 f2 0b                 dw      at      ; contains vocabulary address
R    0754 f2 0b                 dw      at      ; contains the latest entry
R    0756 2c 13                 dw      search  ; search the vocabulary
R    0758 40 08                 dw      p_if    ; if false, found; otherwise
R    075a 0a                            db      tick1-$
     075b 03 10                 dw      entry   ; get latest current
     075d 2c 13                 dw      search  ; search current
     075f 40 08                 dw      p_if    ; if false, found; otherwise
     0761 03                            db      tick1-$
     0762 c0 12                 dw      question        ; echo token and ?
R    0764 31 00         tick1:  dw      psemi

Here we see that the “‘“ keyword was executed; the “R” meaning the leading byte was read, in this case by the inner interpreter’s execution of the word. We also see that every time it was executed, it found the word in the CONTEXT vocabulary and never searched the CURRENT vocabulary.

Armed with this, I started writing an expect script that feeds input to ZIP, collecting and reporting the code coverage data.

I run the script, examine the coverage report and add new tests to the script that exercise unused code paths.

2024-01-27 Debugging ZIP

Charles Anthony — Wed, 07 Feb 2024 04:23:17 +0000

Finished transcribing all of the words in Chapter 6.

Now to debug them…

First, see if I can get MartyG’s simulation running…

Altair 8800 (Z80) simulator Open SIMH V4.1-0 Current        git commit id: 625b9e8d+uncommitted-changes
/home/cac/Projects/zip/MartyG/mg.ini-3> set cpu verbose
8192 bytes [32 pages] loaded at f000.
Warning: 16 pages modified.
/home/cac/Projects/zip/MartyG/mg.ini-7> g F000
%SIM-INFO: SIGINT will be delivered to your debugger when the ^F character is entered
#

Z80 ROM MONITOR V5.04 - LOW PAGE (J.Monahan,7/29/2014) 
SP=FFFF  IOBYTE= 11111111

->

But if a type a character, it goes berserk, like a was holding the character down. Reviewing the ROM listings to see if I can decipher the port bits.

2024-01-24 Debugging ZIP

Charles Anthony — Wed, 07 Feb 2024 03:02:31 +0000

Added

*
*+LOOP
*/
*/MOD
*C+LOOP
*CDO
*CLEAVE
*CLOOP
*DO
*END
*LEAVE
*LOOP
*[
+LOOP
+SP
-SP
.R
/
/MOD
0<
0SET
1+
1-
1SET
2*
2+
2-
2/
2DUP
2OVER
2SWAP
:
;
<BUILDS
<R
C1SET
CONSTANT
CR>
END,

  : FOO 2 * 1 + . ;         OK
  10 FOO                    OK

Hmm. should have printed 21.

Dump memory; looking at the compiled word FOO:

000f3e 03       db      3,"FOO"
000f40 4f
000f41 4f
000f42 2c       dw      vocab link
000f43 0f
000f44 49       dw      p_colon
000f45 00
000f46 d4       dw      cliteral
000f47 07
000f48 02       db      2
000f49 6c       dw      splat
000f4a 07
000f4b e6       dw      two
000f4c 09
000f4d bf       dw      plus
000f4e 08
000f4f 3d       dw      dot
000f50 09
000f51 d4       dw      07d4  cliteral  ???
000f52 07
000f53 10       db      10   
000f54 44
000f55 0f
000f56 01
000f57 80

Hmm. Didn’t go out of compile mode?

Reworked vocabularies

000f4d 03    db 3, “FOO”
000f4e 46
000f4f 4f
000f50 4f
000f51 3b    dw link
000f52 0f
000f53 49    dw p_colon
000f54 00
000f55 d4    dw cliteral
000f56 07
000f57 02    db 2
000f58 6c    dw splat
000f59 07
000f5a e6    dw one
000f5b 09
000f5c bf    dw plus
000f5d 08
000f5e 3d    dw dot
000f5f 09
000f60 01    dw 3b01  ; wrong again
000f61 3b
000f62 00
000f63 00
000f64 00

Did some more vocab rework. TIL is annoying at times

: foo 2 * 1 + . ;  OK
10 foo   OK

So now finding”;” correctly.

000f41 03  db 3,”FOO”
000f42 46
000f43 4f
000f44 4f
000f45 2f  dw link
000f46 0f
000f47 49  dw p_colon
000f48 00
000f49 d4  dw  cliteral
000f4a 07
000f4b 02  db 2
000f4c 6c  dw spalt
000f4d 07
000f4e e6  dw one
000f4f 09
000f50 bf  dw plus
000f51 08
000f52 3d  dw dot
000f53 09
000f54 d4  dw cliteral  ; what? again?
000f55 07
000f56 10
000f57 47
000f58 0f
000f59 01
000f5a 80
000f5b 00

2024-01-23 Debugging ZIP

Charles Anthony — Wed, 07 Feb 2024 03:00:35 +0000

The division problem above was caused by an error in TIL; in D/MOD the line

mov1:     ld      d,a     ; store divisor

Should be

mov1:     ld      e,a     ; store divisor

This sets up the arguments to $UD/ correctly, resulting in a correct division.

Now ZIP can print numbers:

    DP .

yields

   FA  OK

  DP @ .

yields

   C4F OK

Started in on the number interpreter….

Debugging revealed a couple of transcription errors, and a assembly dialect issue:

Where TIL codes “ADC A”, z80asm needs “ADC A,A”, otherwise it assembles an “ADC A,IXL” instruction.

Now zip can

   1000 .

yielding

   1000 OK

ZIP is printing a garbage character at the end of the “.” string. TIL pushes a space character with the high bit set as an end-of-string marker. I suspect that on Loeliger’s system the terminal ignored the high bit and printed an ordinary space. I am adding a bit of code to clear the high bit.

Works:

   !    C!    @   C@

1 2 + 
0 OK

Plus not working.

plus:   dw      $+2     
        pop     hl      ; get first word
        pop     de      ; get second word
        add     hl,de   ; add them
        push    hl      ; push sum
        nxt

That sure looks ok

Heh. I traced “1 2 + .” and it never executed that code. I made a typo; the “=” keyword has an incorrect entry “+”.

Ok, + works.

1 2 + .                3  OK

2000 @ .              0  OK
1234 2000 ! 2000 @ .                1234  OK
56 2000 C!  2000 @ .                1256  OK
2000 C@ .                            56  OK
2000 @ . 10 2000 +! 2000 @ .           1256 1266  OK

+! works

DP @ .                            C52  OK
1234 ,  DP @ .

Crash…. comma not working.

Transcription error; forgot the nxt.

DP @ .                C54  OK
1234 , DP @ .          C56  OK
C54 @ .               1234  OK

comma works

2 1 - .              -1  OK

That’s wrong…

Typo in -1

   db 1, “-1 “

should be

   db 2,”-1”

2 1 - .           1  OK
1 2 - .            -1  OK
-1 .  -1  OK

minus works

1 0= .               0  OK
0 0= .                1  OK
-1 0= .             0  OK
8000 0= .            0  OK

0= works.

1 2+ . 3  OK

2+ works

1 ABS .          1  OK
-1 ABS .         1  OK

0 ASCII .         30  OK
F ASCII .          46  OK

ASPACE .          20  OK

BASE @ . 10  OK

12 C,       crash

Forgot nxt

DP @ .          C56  OK
DP @ C@ .        2  OK
12 C, C56 C@ .    12  OK

C, works

1234 2000 !  2000 C0SET 2000 @ .             1200  OK

C0SET works

Skipping CA!

3 CCONSTANT 3 
`
RESTART

Not good.

CREATE FOO      
RESTART

The problem seems to be in CREATE.

Forgot the trailing semi

CREATE FOO  OK
3 CCONSTANT FOO  OK
FOO . 
FOO ?
DP @ .                 C58  OK
3 CCONSTANT FOO               OK
C58 C@ .                      3  OK
C59 C@ .                      46  OK
C5A C@ .                      4F  OK
C5B C@ .                      4F  OK
FOO 
FOO ?

It is building the dictionary entry correctly, but not finding it. Almost certainly a problem in the vocabulary words.

CURRENT @ .   A11  OK

0a11 3c                         inc     a       ; else bump high

That’s not right.

CURRENT . 0  OK

Ahh. Not initialized?

Ahh. SYS needs to be page aligned.

CURRENT .           10E  OK
CURRENT @ .         9AF  OK
3 CCONSTANT FOO     OK
FOO .               3  OK

Skipping COMPILER, CORE, CONTEXT, CURRENT, DOES>

(Can’t test DOES> without <BUILDS)

1 2 DROP .    1  OK
3 DUP . .        3 3  OK
ENTRY .    
ENTRY ?

Typo; length byte wrong.

ENTRY .      C46  OK
HERE .      C58  OK
LBP .        
LBP ?

Length byte wrong

LBP .       104  OK
1 2 OVER . . .       1 2 1  OK

Skipping R>

1 2 SWAP . .         1 2  OK

Skipping VOCABULAARY

That’s all of the defined words.

Added tick; crashes.

aspace token dp    OK
context @ @ search     OK
. 0  OK
.

Hangs when the address is printed??

Back jump address in *END

' dp .             A9E  OK

Committed and pushed.

Added *

But:

zip.l.asm:841: error: `,' expected. Remainder of line: _uds ; multiply 16x8 

        call    _isign  ; field input signs
        call    p_uds   ; multiply 16x8
        call    _posign ; Justify result

I have no idea what it is complaining about

Huh. no embedded underscores… Ok when defined, fail when referenced… only when referenced by call; jumping to them is okay.

2 2 * . 4  OK

Added

*+LOOP
*/
*/MOD
*C+LOOP
*CDO
*CLEAVE
*CLOOP
*DO
*LEAVE
*LOOP

2024-01-21 Debugging ZIP

Charles Anthony — Wed, 07 Feb 2024 02:47:42 +0000

Updated zipd.txt; it now feeds "foo" to ZIP; going to debug the "not found" path.

ZIP
foo 
:��>2�1 ?

inner  0057     outer
inner  0BEA       type
inner  0075       inline
inner  08EA       aspace
inner  0BB3       token
inner  088F       qsearch
inner  0976         context
inner  08C5         at
inner  08C5         at
inner  0B2E         search
inner  0A31         dup
inner  0758         p_if
inner  0A71         mode
inner  0927         cat
inner  0758         p_if
inner  0031         semi
inner  0758       p_if
inner  085A       qnumber
inner  0A7A         number
inner  0758         p_if
inner  080A         one
inner  0031         semi
inner  0743       p_end
inner  0AEA       question
inner  0057     outer
inner  0BEA       type
inner  0075       inline

It gets to QUESTION ok, so the problem is probably in there.

In QUESTION, the address of the unrecognized token is passed to TYPE, but TYPE expects the address on the stack: (It may be that the the _type label should be one instruction farther down (past the POP HL), but I decided that a consistent API was preferable.

Changed:

        dec     hl      ; back-up to token length
        jp      _type   ; go echo unknown token

to:

        dec     hl      ; back-up to token length
        push    hl      ; XXX Fix added by CAC; type expects the address on the stack.
        jp      _type   ; go echo unknown token

Now:

ZIP
FOO 
FOO ?

Next up: get “.” implemented.

ZIP
DP . ��

inner  07E8         dot
inner  083A           sharpbegin
inner  08FC            abs
inner  06B8            sharps
inner  0695              sharp
inner  07FC                zero
inner  0932                base
inner  0966                cat
inner  09EC                ddmod
inner  0913                ascii
inner  0BDC                swap
inner  0031                semi
inner  0A70              dup
inner  080A              zeq
inner  0743              p_end
inner  0695              sharp
inner  07FC                zero
inner  0932                base
inner  0966                cat
inner  09EC                ddmod
inner  0913                ascii
inner  0BDC                swap
inner  0031                semi
inner  0A70              dup
inner  080A              zeq
inner  0743              p_end
inner  0695              sharp
. . .

It keeps looping in #S (sharps)

: #S BEGIN # DUP 0 = END DROP ;

Looking at the ABS

08fe d1                         pop     de      ; get number
CPU: C0Z0S0V0H0N0 A =08 BC =07EE DE =00FA HL =08FE S =0331 P =08FE POP DE

00FA is correct (the address of DP).

‘zero’ pushes a zero on the stack.

‘base cat’ pushes 16 on the stack.

ddmod:

09ef e1                         pop     hl      ; get 8 bit divisor
CPU: C0Z1S0V0H0N1 A =09 BC =0000 DE =0006 HL =0010 S =032D P =09EF POP HL

Divisor is 16; correct

09f0 d1                         pop     de      ; 8 most significant
CPU: C0Z1S0V0H0N1 A =09 BC =0000 DE =0000 HL =0010 S =032F P =09F0 POP DE

09f1 c1                         pop     bc      ; get 16 least
CPU: C0Z1S0V0H0N1 A =09 BC =00FA DE =0000 HL =0010 S =0331 P =09F1 POP BC

dividend is 0000FA; correct

09f2 7c                         ld      a,h     ; divisor sign
CPU: C0Z1S0V0H0N1 A =00 BC =00FA DE =0000 HL =0010 S =0331 P =09F2 LD A,H

09f3 aa                         xor     d       ; result sign
CPU: C0Z1S0V1H0N0 A =00 BC =00FA DE =0000 HL =0010 S =0331 P =09F3 XOR D

09f4 08                         ex      af,af'  ; save sign flag
CPU: C0Z0S0V0H1N0 A =02 BC =00FA DE =0000 HL =0010 S =0331 P =09F4 EX AF,AF'
                  A'=00 BC'=069F DE'=09EE HL'=09EE IX=0528 IY=003D

Sign flag is 0; correct

09f5 7d                         ld      a,l     ; get dividend sign
CPU: C0Z0S0V0H1N0 A =10 BC =00FA DE =0000 HL =0010 S =0331 P =09F5 LD A,L

09f6 a7                         and     a       ; test sign
CPU: C0Z0S0V0H1N0 A =10 BC =00FA DE =0000 HL =0010 S =0331 P =09F6 AND A

09f7 f2 fc 09                   jp      p,mov1  ; if +, its ok
CPU: C0Z0S0V0H1N0 A =10 BC =00FA DE =0000 HL =0010 S =0331 P =09F7 JP P,09FCh

Dividend is positive; correct.

09fc 57                 mov1:   ld      d,a     ; store divisor
CPU: C0Z0S0V0H1N0 A =10 BC =00FA DE =1000 HL =0010 S =0331 P =09FC LD D,A

09fd 60                         ld      h,b     ; get 16 least
CPU: C0Z0S0V0H1N0 A =10 BC =00FA DE =1000 HL =0010 S =0331 P =09FD LD H,B

09fe 69                         ld      l,c     ; to hl
CPU: C0Z0S0V0H1N0 A =10 BC =00FA DE =1000 HL =00FA S =0331 P =09FE LD L,C
HL is 00FA; correct.

09ff 7b                         ld      a,e     ; get 8 most
CPU: C0Z0S0V0H1N0 A =00 BC =00FA DE =1000 HL =00FA S =0331 P =09FF LD A,E

0a00 a7                         and     a       ; test sign
CPU: C0Z1S0V1H1N0 A =00 BC =00FA DE =1000 HL =00FA S =0331 P =0A00 AND A

0a01 f2 0e 0a                   jp      p,mov2  ; if +. its ok
CPU: C0Z1S0V1H1N0 A =00 BC =00FA DE =1000 HL =00FA S =0331 P =0A01 JP P,0A0Eh

Dividend is positive; correct.

0a0e 57                 mov2:   ld      d,a     ; move high 8
CPU: C0Z1S0V1H1N0 A =00 BC =00FA DE =0000 HL =00FA S =0331 P =0A0E LD D,A

0a0f cd 0e 07                   call    pudd    ; divide 24X8
CPU: C0Z1S0V1H1N0 A =00 BC =00FA DE =0000 HL =00FA S =032F P =0A0F CALL 070Eh

070e 06 10              pudd:   ld      b, 16   ; divide count 16
CPU: C0Z1S0V1H1N0 A =00 BC =10FA DE =0000 HL =00FA S =032F P =070E LD B,10h

0710 29                 dloop1: add     hl,hl   ; shift low 16
CPU: C0Z1S0V1H0N0 A =00 BC =10FA DE =0000 HL =01F4 S =032F P =0710 ADD HL,HL

HL is 01F4 (00FA + 00FA); correct.

0711 7a                         ld      a,d     ; get high 8
CPU: C0Z1S0V1H0N0 A =00 BC =10FA DE =0000 HL =01F4 S =032F P =0711 LD A,D

0712 8a                         adc     a,d     ; shift high 8
CPU: C0Z1S0V0H0N0 A =00 BC =10FA DE =0000 HL =01F4 S =032F P =0712 ADC A,D

A is 0 (0 + 0); correct.

0713 57                         ld      d,a     ; restore high
CPU: C0Z1S0V0H0N0 A =00 BC =10FA DE =0000 HL =01F4 S =032F P =0713 LD D,A

0714 93                         sub     e       ; subtract divisor
CPU: C0Z1S0V0H0N1 A =00 BC =10FA DE =0000 HL =01F4 S =032F P =0714 SUB E

0715 fa 1a 07                   jp      m,skip1 ; too much, it;s ok
CPU: C0Z1S0V0H0N1 A =00 BC =10FA DE =0000 HL =01F4 S =032F P =0715 JP M,071Ah

0718 2c                         inc     l       ; set result low bit = 1
CPU: C0Z0S1V0H0N0 A =00 BC =10FA DE =0000 HL =01F5 S =032F P =0718 INC L

0719 57                         ld      d,a     ; decrease dividend
CPU: C0Z0S1V0H0N0 A =00 BC =10FA DE =0000 HL =01F5 S =032F P =0719 LD D,A

071a 10 f4              skip1:  djnz    dloop1  ; loop 16 times
CPU: C0Z0S1V0H0N0 A =00 BC =0FFA DE =0000 HL =01F5 S =032F P =071A DJNZ 0710h

. . .

071a 10 f4              skip1:  djnz    dloop1  ; loop 16 times 
CPU: C0Z0S1V0H0N1 A =FA BC =00FA DE =FA00 HL =FFFE S =032F P =071A DJNZ 0710h

071c 4a                         ld      c,d     ; remainder to C
CPU: C0Z0S1V0H0N1 A =FA BC =00FA DE =FA00 HL =FFFE S =032F P =071C LD C,D

071d c9                         ret             ; quotient in HL 
CPU: C0Z0S1V0H0N1 A =FA BC =00FA DE =FA00 HL =FFFE S =0331 P =071D RET
                  A'=00 BC'=069F DE'=09EE HL'=09EE IX=0528 IY=003D

0000FA / 10 => quotient F, remainder A

Wrong; code returned quotient FFFE, remainder FA.

2024-01-20 Debugging ZIP

Charles Anthony — Wed, 07 Feb 2024 02:36:04 +0000

Fetch the latest code: "git pull".

This will fetch "zipd.ini" and "dp.txt"

"zipd.ini" Loads ZIP, configures instruction tracing, sets the file "dp.txt" as the source of keyboard input, runs ZIP for 8,192 instructions. It writes the instruction trace to the file “zip.debug” and quits.

zip.ini:

set debug -N zip.debug
set cpu z80
load zip.bin
dep pc 0

attach sio foo.txt

set cpu history=8192
s 8192
show cpu history=8192
q

"dp.txt" contains the text "DP\r"; when this is input to ZIP, ZIP should parse the "DP" token and search for it in the dictionary. Upon finding it, it should then execute the DP primitive which will push the current value of the dictionary pointer to the stack. It should continue parsing, find the end of the input buffer, print "OK" and wait for additional input.

altairz80 zipd.ini

A bunch of stuff will fly by; ignore it, everything is captured in the file “zip.debug”. Editing it, we see at the top:

zipd.ini-1> set debug -N zip.debug
%SIM-INFO: Debug output to "zip.debug"
Debug output to "zip.debug" at Sat Jan 20 10:17:25 2024
Altair 8800 (Z80) simulator Open SIMH V4.1-0 Current        git commit id: 625b9e8d+uncommitted-changes
2921 bytes [12 pages] loaded at 0.


Step expired, PC: 09AA4 (NOP)
CPU: C0Z0S0V0H0N0 A =00 BC =0000 DE =0102 HL =0000 S =0000 P =0000 LD DE,0102h
                  A'=00 BC'=0000 DE'=0000 HL'=0000 IX=0000 IY=0000
CPU: C0Z0S0V0H0N0 A =00 BC =0000 DE =0102 HL =0000 S =0000 P =0003 LD A,(00F4h)
                  A'=00 BC'=0000 DE'=0000 HL'=0000 IX=0000 IY=0000
CPU: C0Z1S0V1H1N0 A =00 BC =0000 DE =0102 HL =0000 S =0000 P =0006 AND A
                  A'=00 BC'=0000 DE'=0000 HL'=0000 IX=0000 IY=0000
CPU: C0Z1S0V1H1N0 A =00 BC =0000 DE =0102 HL =0000 S =0000 P =0007 JR NZ,0011h
                  A'=00 BC'=0000 DE'=0000 HL'=0000 IX=0000 IY=0000
CPU: C0Z1S0V1H1N0 A =10 BC =0000 DE =0102 HL =0000 S =0000 P =0009 LD A,10h

And at the bottom:

CPU: C0Z0S1V0H0N0 A =07 BC =0074 DE =074A HL =810A S =010B P =9A9C NOP
                  A'=03 BC'=0000 DE'=0006 HL'=097D IX=030F IY=003D
CPU: C0Z0S1V0H0N0 A =07 BC =0074 DE =074A HL =810A S =010B P =9A9D NOP
                  A'=03 BC'=0000 DE'=0006 HL'=097D IX=030F IY=003D
CPU: C0Z0S1V0H0N0 A =07 BC =0074 DE =074A HL =810A S =010B P =9A9E NOP 
                  A'=03 BC'=0000 DE'=0006 HL'=097D IX=030F IY=003D
CPU: C0Z0S1V0H0N0 A =07 BC =0074 DE =074A HL =810A S =010B P =9A9F NOP
                  A'=03 BC'=0000 DE'=0006 HL'=097D IX=030F IY=003D
CPU: C0Z0S1V0H0N0 A =07 BC =0074 DE =074A HL =810A S =010B P =9AA0 NOP
                  A'=03 BC'=0000 DE'=0006 HL'=097D IX=030F IY=003D
CPU: C0Z0S1V0H0N0 A =07 BC =0074 DE =074A HL =810A S =010B P =9AA1 NOP
                  A'=03 BC'=0000 DE'=0006 HL'=097D IX=030F IY=003D
CPU: C0Z0S1V0H0N0 A =07 BC =0074 DE =074A HL =810A S =010B P =9AA2 NOP
                  A'=03 BC'=0000 DE'=0006 HL'=097D IX=030F IY=003D
CPU: C0Z0S1V0H0N0 A =07 BC =0074 DE =074A HL =810A S =010B P =9AA3 NOP
                  A'=03 BC'=0000 DE'=0006 HL'=097D IX=030F IY=003D
Goodbye

The script annotate.sh processes the trace file and merges the assembler listing file into it:

./annotate.sh < zip.debug > zip.debug.annotate

Editing "zip.debug.annotate", we see:

0000                          _start:
0000 11 02 01                           ld        de, rstmsg          ; restart message address to WA
CPU: C0Z0S0V0H0N0 A =00 BC =0000 DE =0102 HL =0000 S =0000 P =0000 LD DE,0102h
                  A'=00 BC'=0000 DE'=0000 HL'=0000 IX=0000 IY=0000

The lines from the listing file corresponding to the address of the executed instructions have been pre-pended to each instruction trace.

Tracing the inner interpreter
The inner interpreter starts at the label next:

; WA <= @IR
; IR += 2
next:     ld        a,(bc)    ; low byte of *IR
          ld        l,a       ; into L
          inc       bc        ; IR ++
          ld        a,(bc)    ; high byte of *IR
          ld        h,a       ; into H
          inc       bc        ; IR ++ 

; CA <= @WA
; WA += 2
; PC <= CA

run:      ld        e,(hl)
          inc       hl
          ld        d,(hl)
          inc       hl
          ex        de,hl
; the 'go' label is for the debugging tools
go:       jp        (hl)

At the label run, HL points to the code field of the word to be executed. Typically, there are coded like:

          db        3,"DUP"
          __link__
dup:      dw        $+2
          pop       hl
          push      hl
          push      hl
          nxt

In this case, the code word of the DUP word is labeled “dup”; most of the code words in the ZIP source are labeled with a assembler-legal label. The annotate.sh script can leverage that to trace the inner interpreter. The script reads the symbol table (zip.sym) generated by the assembler, and when it sees in the instruction trace that the instruction at the label run is executed, it extracts the HL value from the trace, looks that value up in the symbol table and reports the symbol name:

$ ./annotate.sh < zip.debug | grep "^inner"
inner  0057   outer
inner  0B49   type
inner  0075   inline
inner  086C   aspace
inner  0B12   token
inner  080F   qsearch
inner  08EB   context
inner  0847   at
inner  0847   at
inner  0A8D   search
inner  0991   dup
inner  0734   p_if
inner  0031   semi
inner  0734   p_if
inner  07A2   q_execute
inner  08EB   context
inner  0847   at
inner  0847   at
inner  0A8D   search
inner  0991   dup
inner  0734   p_if
inner  0031   semi
inner  0748   p_while

At the same time, we can examine the stack pointer and indent the labels to help keep track of nesting:

$ grep "^inner" zip.debug.annotate
inner  0057     outer
inner  0B49       type
inner  0075       inline
inner  086C       aspace
inner  0B12       token
inner  080F       qsearch
inner  08EB         context
inner  0847         at
inner  0847         at
inner  0A8D         search
inner  0991         dup
inner  0734         p_if
inner  0031         semi
inner  0734       p_if
inner  07A2       q_execute
inner  08EB         context
inner  0847         at
inner  0847         at
inner  0A8D         search
inner  0991         dup
inner  0734         p_if
inner  0031         semi
inner  0748       p_while

Looking at the source for outer:

outer:    dw        p_colon
          dw        type
          dw        inline
outer1:   dw        aspace
          dw        token
          dw        qsearch
          dw        p_if
          db        outer3-$
outer2:   dw        qnumber
          dw        p_end
          db        outer1-$
          dw        question
          dw        p_while
          db        outer-$
outer3:   dw        q_execute
          dw        p_while
          db        outer1-$

It did the TYPE, INPUT, ASPACE, TOKEN and ?SEARCH. The search succened, so the IF jumped down to the ?EXECUTE:

;  : ?EXECUTE
;      CONTEXT @ @
;      SEARCH
;      DUP IF
;        MODE C@ IF
;         DROP
;         COMPILER @
;         SEARCH
;         DUP IF
;           0
;         ELSE
;           1
;         THEN
;         STATE
;         C!
;       THEN
;     THEN ;

          ; headerless
q_execute:
          dw        p_colon
          dw        context
          dw        at
          dw        at
          dw        search
          dw        dup
          dw        p_if
          db        .q3-$
          dw        cat
          dw        p_if
          db        .q3-$
          dw        drop
          dw        compiler
          dw        at
          dw        search
          dw        dup
          dw        p_if
          db        .q1-$
          dw        cliteral
          db        0
          dw        p_else
          db        .q2-$
.q1:      dw        cliteral
          db        1
.q2:      dw        state
          dw        cstore
.q3:      dw        semi

Cross checking with TIL; I did a transcription error, missed the MODE word.

          dw        p_if
          db        .q3-$
          dw        mode
          dw        cat

Oh, wait. I transcribed the wrong code; ?EXECUTE is completely wrong. Re-transcribing.

Adding *STACK, =, and C0SET needed by ?EXECUTE.

Fixed typos in *ELSE and *WHILE.

Now it gets hard; it doesn’t crash, it just goes crazy.