RLV12 V2.0 Logging


Logging

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

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
  • Controller Functions
  • Physical Block Number

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

The software can also log all controller 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

]log
Logging device register access .: off
Logging Interrupts .............: off
Logging Physical Block Nbr. ....: 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

]log reg

]logging
Logging device register access .: on
Logging Interrupts .............: off
Logging Physical Block Nbr. ....: 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 log units

]log
Logging device register access .: on
Logging Interrupts .............: off
Logging Physical Block Nbr. ....: 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

]log rl1

]log
Logging device register access .: on
Logging Interrupts .............: off
Logging Physical Block Nbr. ....: on
Logging unit 0 .................: off
Logging unit 1 .................: on
Logging unit 2 .................: off
Logging unit 3 .................: off

]

or you can deactivate all logging with

]no log

]log
Logging device register access .: off
Logging Interrupts .............: off
Logging Physical Block Nbr. ....: off
Logging unit 0 .................: off
Logging unit 1 .................: off
Logging unit 2 .................: off
Logging unit 3 .................: off

]

The logging of physical block numbers can be switch on or off by using the logging pbn or no logging pbn command and shows the translation of the block requested by the host to the physical block number on the SD-Card. Again mostly useful during debugging. Now the PBN logging reports the first block and the number of blocks read or written by the controller command.

The logging of interrupts can also be switched on or off by using the logging interrupt or no logging interrupt command.

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

]show logg
Read  (00,t:2D) CSR:000205
Read  (03,t:2E) MPR:000235
Read  (00,t:30) CSR:000205
Write (02,t:37) DAR:007005
Write (00,t:39) CSR:000006
SEEK: V:0 C:000024 O:+034->007024 H:0
Read  (00,t:3B) CSR:000207
Read  (03,t:3D) MPR:000000
Read  (00,t:3E) CSR:000207
Write (03,t:41) MPR:175400
Write (02,t:43) DAR:007036
Write (01,t:44) BAR:007356
Write (04,t:48) BAE:000000
Write (00,t:4C) CSR:000114
READ: V:0 A:00007356(0x000EEE) D:007036(L:0x046F) C:175400(E:0x0018EE)
          P:0x00000471 N:0x0005
IACK     (t:46) VEC:000160
Read  (00,t:76) CSR:000315
Write (02,t:85) DAR:000021
Write (00,t:86) CSR:000006
SEEK: V:0 C:007050 O:-000->007050 H:1
Read  (00,t:89) CSR:000207
Read  (03,t:8B) MPR:000000
Read  (00,t:8C) CSR:000207
Write (03,t:8F) MPR:177617
Write (02,t:91) DAR:007100
Write (01,t:92) BAR:014356
Write (04,t:96) BAE:000000
Write (00,t:99) CSR:000114
READ: V:0 A:00014356(0x0018EE) D:007100(L:0x0474) C:177617(E:0x0019D0)
          P:0x00000476 N:0x0001
IACK     (t:95) VEC:000160
Read  (00,t:B8) CSR:000315
Write (02,t:4B) DAR:000003
Write (00,t:4D) CSR:000004
GETS: V:0 S:000335
Read  (00,t:50) CSR:000205
Read  (03,t:52) MPR:000335
Read  (00,t:53) CSR:000205
Write (02,t:5E) DAR:000013
Write (00,t:60) CSR:000004
GETS: V:0 S:000335
Read  (00,t:63) CSR:000205
Read  (03,t:64) MPR:000335
Read  (00,t:65) CSR:000205
Write (02,t:68) DAR:000003
Write (00,t:6A) CSR:000004
GETS: V:0 S:000335
Read  (00,t:6D) CSR:000205
Read  (03,t:6E) MPR:000335
Read  (00,t:6F) CSR:000205
Write (02,t:77) DAR:003601
Write (00,t:79) CSR:000006
SEEK: V:0 C:007101 O:-017->003301 H:0
Read  (00,t:7B) CSR:000207
Read  (03,t:7D) MPR:000000
Read  (00,t:7E) CSR:000207
Write (03,t:85) MPR:173000
Write (02,t:86) DAR:003224
Write (01,t:88) BAR:066000
Write (04,t:8C) BAE:000000
Write (00,t:90) CSR:000114
READ: V:0 A:00066000(0x006C00) D:003224(L:0x0212) C:173000(E:0x008000)
          P:0x00000214 N:0x000A
IACK     (t:14) VEC:000160
Read  (00,t:3C) CSR:000315
Write (02,t:48) DAR:000021
Write (00,t:4A) CSR:000006
SEEK: V:0 C:003250 O:-000->003250 H:1
Read  (00,t:4D) CSR:000207
Read  (03,t:4F) MPR:000000
Read  (00,t:50) CSR:000207
Write (03,t:53) MPR:170000
Write (02,t:54) DAR:003300
Write (01,t:56) BAR:100000
Write (04,t:5A) BAE:000000
Write (00,t:5D) CSR:000114
READ: V:0 A:00100000(0x008000) D:003300(L:0x021C) C:170000(E:0x00A000)
          P:0x0000021E N:0x0010
IACK     (t:F5) VEC:000160
Read  (00,t:16) CSR:000315

Note that show logging will also reset the logging buffer.

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 see 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:0x0000021E N:0x0010
READ: V:2 A:01027470(0x042F38) D:061424(L:0x1EFA) C:177400(E:0x043138)
          P:0x0000021E N:0x0010
RDHD: V:2 D:061443
SEEK: V:2 C:061445 O:+072->100045 H:0
Code Description
V: Volume/Unit number
S: Status of the selected unit sent to the PDP-11
A: Memory DMA address in octal and (hex)
D: Disk address in octal
L: Corresponding logical block number of the disk image file or partition
C: Word count register in octal
N: Number of blocks read or written to the SD-Card for Physical Block Nbr logging
E: Memory DMA address after transfer
P: Physical block number on the SD-Card of the last sector of the IO request
O: Track Offset, number of tracks the header should move
t: Time stamp of register read or write in ticks

Timestamp

The logging of device register access and interrupts inlcudes a timestamp. 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.

Write (02,t:FA) DAR:000003
Write (00,t:FE) CSR:000004
Read  (00,t:01) CSR:000205
Read  (03,t:03) MPR:000335
Read  (00,t:04) CSR:000205
Write (02,t:1D) DAR:000013
Write (00,t:1F) CSR:000004
Read  (00,t:21) CSR:000205
Read  (03,t:22) MPR:000335
Read  (00,t:24) CSR:000205
Write (02,t:26) DAR:000003
Write (00,t:28) CSR:000004
Read  (00,t:2B) CSR:000205
Read  (03,t:2C) MPR:000335
Read  (00,t:2D) CSR:000205
Write (02,t:3F) DAR:003201
Write (00,t:41) CSR:000006
Read  (00,t:43) CSR:000207
Read  (03,t:45) MPR:000000
Read  (00,t:46) CSR:000207
Write (03,t:4D) MPR:177000
Write (02,t:4E) DAR:000014
Write (01,t:50) BAR:107000
Write (04,t:57) BAE:000000
Write (00,t:5B) CSR:000114
Read  (00,t:3D) CSR:000315
Write (02,t:C1) DAR:000003
Write (00,t:C3) CSR:000004
Read  (00,t:C5) CSR:000205
Read  (03,t:C7) MPR:000235
Read  (00,t:C8) CSR:000205
Write (02,t:D2) DAR:000013
Write (00,t:D4) CSR:000004
Read  (00,t:D6) CSR:000205
Read  (03,t:D7) MPR:000235
Read  (00,t:D9) CSR:000205
Write (02,t:DB) DAR:000003
Write (00,t:DD) CSR:000004
Read  (00,t:DF) CSR:000205