Logging

Sometimes things don’t work as expected. Therefore I have built a logging function into the controller software. There are several logging options that can be switched on or off

Remark

The command itself has not changed with the RLV12 Emulator V2 however I have added a timestamp to the register logging output.

GETS: V:0 S:000335
Read  (00,t:E7) CSR:000005
Read  (00,t:E8) CSR:000005
Read  (00,t:E9) CSR:000205
Read  (03,t:EA) MPR:000335
Read  (00,t:EB) CSR:000205
Write (02,t:EF) DAR:003601
Write (00,t:F1) CSR:000006
Read  (00,t:F2) CSR:000206
Read  (03,t:F3) MPR:000000
Read  (00,t:F4) CSR:000207
Write (03,t:F6) MPR:173000
Write (02,t:F7) DAR:003224
Write (01,t:F8) BAR:066000
Write (04,t:FA) BAE:000000
Write (00,t:FB) CSR:000114
READ: V:0 A:00066000(0x006C00) D:003224(L:0x0212) C:173000(E:0x008000)
          P:0x0000021D C:0x004D
IACK      t:7A
Read  (00,t:8B) CSR:000315
Write (02,t:90) DAR:000021
Write (00,t:92) CSR:000006
Read  (00,t:92) CSR:000206
Read  (03,t:94) MPR:000000
Read  (00,t:94) CSR:000206
Write (03,t:96) MPR:170000
Write (02,t:98) DAR:003300
Write (01,t:98) BAR:100000
Write (04,t:9A) BAE:000000
Write (00,t:9C) CSR:000114
READ: V:0 A:00100000(0x008000) D:003300(L:0x021C) C:170000(E:0x00A000)
          P:0x0000022D C:0x004D
IACK      t:93
Read  (00,t:A5) CSR:000315
Message buffer:
READ: V:0 A:00100000(0x008000) D:003300(L:0x021C) C:170000(E:0x00A000)

The timestamp is implemented as a free running 8-bit counter in the MCU clock by the MCU CPU frequency divided by 128. As the MCU is running at 22.1184MHz one tick corresponds to approx 5.8µs. This showed to be very useful for debugging. Also I have added a new entry in the logging that is created when the MCU issues a PDP-11 interrupt. From this you can actually see how long it took to perform an IO provided the operating system uses interrupts.

What is logged

The emulator implements a cyclical logging buffer. The logging buffer is implemented as a 4096bytes large memory buffer and each logging entry is exactly 8 bytes long. The following activities can create a logging entry

• Access to any of the device registers
• Interrupt Acknowledge
• Any disk function

The software can log all DATI and DATO cycles to any of the device registers.

The software can also log all functions requested by the CPU, like Seek, Read, Write, etc. and also creates a log entry when the MCU generates an PDP-11 interrupt.

Show current settings

Per default only logging of disk functions to all volumes is activated. However you can dynamically enable or disable logging for access to the device register or any of the volumes. Entering only the logging keyword shows the current logging switches

>logging
Logging device register access .: off
Logging Interrupts .............: on
Logging unit 0 .................: on
Logging unit 1 .................: on
Logging unit 2 .................: on
Logging unit 3 .................: on
>

You can activate logging for read or write access to the device registers

>logging register

>logging
Logging device register access .: on
Logging Interrupts .............: on
Logging unit 0 .................: on
Logging unit 1 .................: on
Logging unit 2 .................: on
Logging unit 3 .................: on

>

and you can switch off logging to the units

>no logging units

>      
>logging
Logging device register access .: on
Logging unit 0 .................: off
Logging unit 1 .................: off
Logging unit 2 .................: off
Logging unit 3 .................: off

>

or you can activate logging to a individual unit

>logging rl0

>logging
Logging device register access .: on
Logging Interrupts .............: on
Logging unit 0 .................: on
Logging unit 1 .................: off
Logging unit 2 .................: off
Logging unit 3 .................: off

>

or you can deactivate all logging with

>no logging

>logging
Logging device register access .: off
Logging Interrupts .............: off
Logging unit 0 .................: off
Logging unit 1 .................: off
Logging unit 2 .................: off
Logging unit 3 .................: off

>

With show logging you can display the content of the logging buffer

>show logg
          P:0x0000EFB2
GETS: V:2 S:000335
GETS: V:2 S:000335
GETS: V:2 S:000335
RDHD: V:2 D:177342
SEEK: V:2 C:177343 O:-467->061443 H:0
READ: V:2 A:01027470(0x042F38) D:061424(L:0x1EFA) C:177400(E:0x043138)
          P:0x0000BEFE N:0x0001
GETS: V:2 S:000235
GETS: V:2 S:000235
GETS: V:2 S:000235
RDHD: V:2 D:061443
WRIT: V:2 A:01027470(0x042F38) D:061424(L:0x1EFA) C:177400(E:0x043138)
          P:0x0000BEFE N:0x0001
GETS: V:2 S:000235
GETS: V:2 S:000235
GETS: V:2 S:000235
RDHD: V:2 D:061444
SEEK: V:2 C:061445 O:+072->100045 H:0
WRIT: V:2 A:01026462(0x042D32) D:100000(L:0x2800) C:177400(E:0x042F32)
          P:0x0000C804 N:0x0001
GETS: V:2 S:000235

Note that show logging will reset the logging buffer. Also when the lollipop logging buffer has been activated, which captures the first log entries in a dedicated memory section that is never overwritten, you will be asked midway whether you want to continue with the circular log after the initial log has been displayed.

Continue [Y]
Printing Circular Logging
Read  (03,t:2A) MPR:000235
Read  (00,t:2C) CSR:000605
Write (02,t:4A) DAR:000013
Write (00,t:4B) CSR:000404
GETS: V:1 S:000235
Read  (00,t:4E) CSR:000605
Read  (03,t:50) MPR:000235
Read  (00,t:51) CSR:000605
Write (02,t:54) DAR:000003
Write (00,t:56) CSR:000404
GETS: V:1 S:000235
Read  (00,t:59) CSR:000605
Read  (03,t:5A) MPR:000235
Read  (00,t:5C) CSR:000605
Write (02,t:6E) DAR:040601
Write (00,t:70) CSR:000406
SEEK: V:1 C:040642 O:-203->000042 H:0
Read  (00,t:73) CSR:000607
Read  (03,t:75) MPR:000000
Read  (00,t:76) CSR:000607
Write (03,t:7D) MPR:177000
Write (02,t:7F) DAR:000034
Write (01,t:80) BAR:117350
Write (00,t:83) CSR:000514
READ: V:1 A:00117350(0x009EE8) D:000034(L:0x000E) C:177000 E:00121350(0x00A2E8)
          P:0x00088FC2 N:0x0002
IACK     (t:23) VEC:000160
Read  (00,t:45) CSR:000715
Write (02,t:7F) DAR:000003
Write (00,t:83) CSR:000404
GETS: V:1 S:000235
Read  (00,t:86) CSR:000605
Read  (03,t:88) MPR:000235
Read  (00,t:8A) CSR:000605
Write (02,t:98) DAR:000013
Write (00,t:9A) CSR:000404
GETS: V:1 S:000235
Read  (00,t:9D) CSR:000605
Read  (03,t:9E) MPR:000235
Read  (00,t:A0) CSR:000605
Write (02,t:A2) DAR:000003
Write (00,t:A4) CSR:000404
GETS: V:1 S:000235
Read  (00,t:A8) CSR:000605
Read  (03,t:A9) MPR:000235
Read  (00,t:AA) CSR:000605
Write (03,t:B0) MPR:177000
Write (02,t:B2) DAR:000040
Write (01,t:B3) BAR:117350
Write (00,t:B4) CSR:000514
READ: V:1 A:00117350(0x009EE8) D:000040(L:0x0010) C:177000 E:00121350(0x00A2E8)
          P:0x00088FC4 N:0x0002
IACK     (t:54) VEC:000160
Read  (00,t:71) CSR:000715

Description of logging entries

Logging of Device Register access

For each DATI or DATOB cycle a log entry is created with

Write (C2,t:E7) DAR:000003
Write (C0,t:E8) CSR:000004
Read  (C3,t:E9) MPR:000335
Write (C2,t:EA) DAR:000013
Write (C0,t:EB) CSR:000004
Read  (C3,t:EF) MPR:000335
Write (C2,t:F1) DAR:000003
Write (C0,t:F2) CSR:000004
Read  (C3,t:F3) MPR:000335
Write (C2,t:F4) DAR:004421
Write (C0,t:F6) CSR:000006
Read  (C3,t:F7) MPR:000000
Write (C3,t:F8) MPR:176400
Write (C2,t:FA) DAR:002542
Write (C1,t:FB) BAR:103502
Write (C0,t:7A) CSR:000114
Write (C2,t:8B) DAR:000205
Write (C0,t:90) CSR:000006
Read  (C3,t:92) MPR:000000
Write (C3,t:92) MPR:166000
Write (C2,t:94) DAR:002600
Write (C1,t:94) BAR:106502
Write (C0,t:96) CSR:000114
Write (C2,t:98) DAR:000021
Write (C0,t:98) CSR:000006
Read  (C3,t:9A) MPR:000000
Write (C3,t:9C) MPR:177400
Write (C2,t:A0) DAR:002700
Write (C1,t:A3) BAR:132502
Write (C0,t:A4) CSR:000114

Write stands for DATO/DATOB cycles and Read stands for DATI cycles. The code in brackets shows the lower 6 address bits of the address bus when BSYNC is asserted and the top two bits indicated if the lower byte (bit 6) and/or upper byte (bit 7) are being accessed. In case of the RLV12 emulator these should always be set as the RLV12 controller only supports word access. Then you will se the name of the register being accessed and the value being written or read.

Logging of disk functions

Disk functions, when logged, create the following logging output. The output shows the function requested (GETS, RDHD, WRIT, READ, SEEK, WCHK). Read with no check is not implemented for the moment. Then it shows which volume (0..3) was used and some status information depending on the function

GETS: V:2 S:000335

WRIT: V:2 A:01026462(0x042D32) D:100000(L:0x2800) C:177400(E:0x042F32)
          P:0x0000C804 N:0x0001

READ: V:2 A:01027470(0x042F38) D:061424(L:0x1EFA) C:177400(E:0x043138)
          P:0x0000BEFE N:0x0001

RDHD: V:2 D:061443

SEEK: V:2 C:061445 O:+072->100045 H:0