Improve our logging.

[skx]

This pull-request updates how our logging is handled, and makes a proof of concept update to S_FIRST and S_NEXT to make it live.

Once complete this will close #245:

• We've added a new log field to the cpm object.
• Before each syscall we update this with the CPU registers.
• The syscalls can add/update the logger object with more fields.
• After the syscall has completed the resulting registers are captured.
• Finally we write a log message.

This results in something like this being logged:

{"time":"2025-06-16T13:18:10.066371786+03:00","level":"DEBUG","msg":"F_SFIRST","input_registers":{"AF":"0062","BC":"0011","DE":"DE9B","HL":"DEA7"},"glob":{"pattern":"????????.???","matches":40},"matches":{"match_10":"!CCP.COM","match_11":"!CTRLC.COM","match_12":"!DEBUG.COM","match_13":"!DISABLE.COM","match_14":"!HOSTCMD.COM","match_15":"!INPUT.COM","match_16":"!OUTPUT.COM","match_17":"!PRNPATH.COM","match_18":"!VERSION.COM","match_19":"#.COM","match_110":".COM","match_111":"A1.COM","match_112":"ASM.ASM","match_113":"ASM.COM","match_114":"ASM.HEX","match_115":"ASM.PRN","match_116":"AUTOEXEC.SUB","match_117":"BE.COM","match_118":"DDT.COM","match_119":"DUMP.COM","match_120":"ED.COM","match_121":"FIND.COM","match_122":"FU.COM","match_123":"HELLO.ASM","match_124":"HELLO.COM","match_125":"HELLO.HEX","match_126":"HELLO.PRN","match_127":"LOAD.COM","match_128":"PAUSE.ASM","match_129":"PAUSE.COM","match_130":"PAUSE.HEX","match_131":"PAUSE.PRN","match_132":"README.MD","match_133":"S.COM","match_134":"SLASH.ASM","match_135":"SLASH.COM","match_136":"SLASH.HEX","match_137":"SLASH.PRN","match_138":"STAT.COM","match_139":"SUBMIT.COM"},"output_registers":{"AF":"0062","BC":"0011","DE":"DE9B","HL":"0000"}}

Or more neatly:

{
  "time": "2025-06-16T13:18:10.066371786+03:00",
  "level": "DEBUG",
  "msg": "F_SFIRST",
  "input_registers": {
    "AF": "0062",
    "BC": "0011",
    "DE": "DE9B",
    "HL": "DEA7"
  },
  "glob": {
    "pattern": "????????.???",
    "matches": 40
  },
  "matches": {
    "match_0": "!CCP.COM",
    "match_1": "!CTRLC.COM",
    "match_2": "!DEBUG.COM",
    "match_3": "!DISABLE.COM",
    "match_4": "!HOSTCMD.COM",
    "match_5": "!INPUT.COM",
    "match_6": "!OUTPUT.COM",
    "match_7": "!PRNPATH.COM",
    "match_8": "!VERSION.COM",
    "match_9": "#.COM",
    "match_10": ".COM",
    "match_11": "A1.COM",
    "match_12": "ASM.ASM",
    "match_13": "ASM.COM",
    "match_14": "ASM.HEX",
    "match_15": "ASM.PRN",
    "match_16": "AUTOEXEC.SUB",
    "match_17": "BE.COM",
    "match_18": "DDT.COM",
    "match_19": "DUMP.COM",
    "match_20": "ED.COM",
    "match_21": "FIND.COM",
    "match_22": "FU.COM",
    "match_23": "HELLO.ASM",
    "match_24": "HELLO.COM",
    "match_25": "HELLO.HEX",
    "match_26": "HELLO.PRN",
    "match_27": "LOAD.COM",
    "match_28": "PAUSE.ASM",
    "match_29": "PAUSE.COM",
    "match_30": "PAUSE.HEX",
    "match_31": "PAUSE.PRN",
    "match_32": "README.MD",
    "match_33": "S.COM",
    "match_34": "SLASH.ASM",
    "match_35": "SLASH.COM",
    "match_36": "SLASH.HEX",
    "match_37": "SLASH.PRN",
    "match_38": "STAT.COM",
    "match_39": "SUBMIT.COM"
  },
  "output_registers": {
    "AF": "0062",
    "BC": "0011",
    "DE": "DE9B",
    "HL": "0000"
  }
}

In short we have one log-line for each syscall, and we have nicely broken down fields. We need to update all the syscalls to follow this approach though which is why this is only a proof of concept.

TODO, before merging

• Update all file I/O functions to work.
• Remove the noisy functions.
• Consider if we need to do something similar for BIOS functions.
• Fix logging of CPU registers in the "after" section.

[skx]

Quite happy with this now; most of the file I/O functions log useful information:

• The actual record(s) read/written.
• The state of the FCB before and after their operations.

The noisy-logging in the past is now gone away, and I can see only a single line of output per BDOS syscall. We've lost the "simple" debugging, which I'm in two minds about, but I think on balance it's an okay trade-off to make.

I rejigged the random-record handling a little which is out of scope really, but made sense to centralize it when I was touching related code.

[skx]

I hit submit too soon! The single outstanding problem I see is that I log CPU registers before and after the syscall, but the "after" values are wrong.

In the BDOS handlers I set HL and rely upon the z80 assembly code I've setup in RAM to propagate the values to B/A registers. But that happens after the return from the golang code, when we're back inside the emulator.

I guess I need to setup the return values more manually, and remove the setting Z80 assembly code I have:

	SETMEM(BDOS+0, 0xED) // OUT (C), C
	SETMEM(BDOS+1, 0x49) //    ""
	//
	////
	/////////////////////// BDOS CALL HAPPENS HERE
	////
	//
	SETMEM(BDOS+2, 0x44) // LD B,H
	SETMEM(BDOS+3, 0x7D) // LD A,L
	SETMEM(BDOS+4, 0xFE) // CP 0
	SETMEM(BDOS+5, 0x00) //    ""
	SETMEM(BDOS+6, 0xC9) // RET