Table of Contents
Module Debugging Walkthrough
On this Wiki Article we'll dive into the topic of debugging a MajorBBS/Worldgroup module, showing how MBBSEmu is setup to assist with debugging not just at an API level but within the emulated x86 Core.
This tutorial assumes you should have a basic understanding of x86 Assembly and C#
Tools
While the tutorial on this page is fairly basic and will only use a couple of the tools listed, to be able to fully debug and work with modules in MBBSEmu, an exhaustive list of tools is provided below:
- Disassembler (any one of the following)
- Development Tools (any one of the following)
Visual Studio 2019 Professional
(Link) RECOMMENDED - Best IDE for debugging and running C# and .Net Core on WindowsVisual Studio Mac
(Link) - Capable IDE from Microsoft for C# and .Net Core development on OSXJetBrains Rider
(Link) - Cross platform IDE for C# and .Net Core Development, best Cross-Platform solution
Exercise
For tutorial we're going to be taking a look at the Character Interceptor Routine registered by GSBL->btuchi()
by Tournament LORD for MajorBBS (RTSLORD
). We'll demonstrate how to set breakpoints within MBBSEmu to capture where different events are being fired as well as how to analyze the x86 Assembly as it goes through the MBBSEmu x86 Emulator.
Starting
The majority of Debug messaging within MBBSEmu is wrapped in a #if DEBUG
preprocessor directive. This is done to maximize the performance of MBBSEmu when compiled in Release
configuration. In order to be able to debug MBBSEmu, you must run it in Debug
configuration to see all available debug messages.
After starting RTSLORD
in MBBSEmu and entering the module as a user, we see the following line in the debug log:
2020-08-16 11:46:14.3331 Info MBBSEmu.HostProcess.ExportedModules.Galgsbl.btuchi Assigned Character Interceptor Routine 0002:1409 to Channel 0
Setting a breakpoint in GSBL.btuchi()
we're able to intercept the call within Visual Studio:
To find out where the call to GSBL.btuchi()
is being invoked, we take a look at the Call Stack and move our stack pointer back to the CpuCore.Tick()
method which is what invoked the API call via an x86 CALL FAR
:
While in the CpuCore.cs
file we can inspect the _currentInstructionPointer
variable to tell us the address of the current instruction being executed:
We can verify the location and disassembly of this instruction by hopping over to IDA and navigating to the SEGMENT:OFFSET address:
The routine being registered to GSBL.btuchi()
is 0002:1409
, so let's start taking a look at how that works.
Capturing Debug
We'll want to setup debugging within the x86 Emulator to output not only the decoded x86 Assembly but also the Register values.
Within the CpuCore.Tick()
method, there is a section at the top wrapped in a #if DEBUG
preprocessor directive. We will use this section to set our debugging settings and breakpoints. Because the emulated x86 core is capable of executing millions of instructions per second, we have to be very specific on what we want to debug. Otherwise the console window is flooded with so much information that it's of little use.
We know the function we want to debug has an entry point address of 0002:1409
, but let's take a look at the disassembly to find where it ends so we know the address range of the function.
The easiest way to accomplish this within IDA is to use the Edit Function
tool which gives you the address range of the function you've selected:
We can see that the address range for the function passed into btuchi()
is 02:1409
->02:1484
. We can now set our debug range within CpuCore.Tick()
and also set a programmatic breakpoint at the end of the function so we can stop our debugging session and take a look at our debug data.
Analyzing Debug
After starting the module and entering it, after the first screen where the btuchi()
function is registered, we'll hit ENTER
and our breakpoint in CpuCore.Tick()
will be hit.
Our console window now contains the captured x86 Assembly and Register values for the range we specified. Let's take a closer look at what's happening.
Functions registered with btuchi()
have the following signature: (*rouadr)(INT channel,INT character)
Knowing this, let's go ahead and label the arguments being passed into the function with their names in IDA to make reading a little easier:
From this, we know that bp+8
is the ASCII character code for our input, and bp+6
is the channel number of the user who it is from. So let's go through and add comments to the IDA disassembly giving the first group of instructions a human readable meaning:
Comparing the disassembled instructions to the debug output looks correct, as CX
is being set to 0xD
(Carriage Return) and the CMP evaluation is coming back as FALSE (Z
flag not set), so the JNZ
instruction is jumping.
2020-08-16 12:24:54.3901 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1415 mov cx,[bp+8] 2020-08-16 12:24:54.3901 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0005 BX=9AE2 CX=000D DX=0100 DS=0005 ES=FFFF 2020-08-16 12:24:54.3901 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=1418 SP=FFE6 BP=FFF1 2020-08-16 12:24:54.3901 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters cpzSo 2020-08-16 12:24:54.3901 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1418 and cx,7Fh 2020-08-16 12:24:54.3901 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0005 BX=9AE2 CX=000D DX=0100 DS=0005 ES=FFFF 2020-08-16 12:24:54.3901 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=141B SP=FFE6 BP=FFF1 2020-08-16 12:24:54.3901 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters cpzso 2020-08-16 12:24:54.3901 Debug MBBSEmu.CPU.CpuCore.Tick 0002:141B cmp cx,1Bh 2020-08-16 12:24:54.3901 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0005 BX=9AE2 CX=000D DX=0100 DS=0005 ES=FFFF 2020-08-16 12:24:54.3901 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=141E SP=FFE6 BP=FFF1 2020-08-16 12:24:54.3901 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters CpzSo 2020-08-16 12:24:54.3901 Debug MBBSEmu.CPU.CpuCore.Tick 0002:141E jne short 1423h 2020-08-16 12:24:54.3901 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1423 cmp cx,0Ch 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0005 BX=9AE2 CX=000D DX=0100 DS=0005 ES=FFFF 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=1426 SP=FFE6 BP=FFF1 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters cpzso
The next two sections are similar in that they're checking for specific ASCII characters and setting the character to '*'
if encountered.
2020-08-16 12:24:54.3901 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1423 cmp cx,0Ch 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0005 BX=9AE2 CX=000D DX=0100 DS=0005 ES=FFFF 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=1426 SP=FFE6 BP=FFF1 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters cpzso 2020-08-16 12:24:54.4044 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1426 jne short 142Bh 2020-08-16 12:24:54.4044 Debug MBBSEmu.CPU.CpuCore.Tick 0002:142B cmp cx,14h 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0005 BX=9AE2 CX=000D DX=0100 DS=0005 ES=FFFF 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=142E SP=FFE6 BP=FFF1 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters CpzSo 2020-08-16 12:24:54.4044 Debug MBBSEmu.CPU.CpuCore.Tick 0002:142E jne short 1433h 2020-08-16 12:24:54.4044 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1433 mov ax,[bp+6] 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0000 BX=9AE2 CX=000D DX=0100 DS=0005 ES=FFFF 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=1436 SP=FFE6 BP=FFF1
In the next block of code, we see reference to a local function variable (var_4
) as well as a pointer that lives in the Data Segment (word_31F50
). To better understand the context for the next block of code, we need to take a detour to learn more about word_31F50
and where it's declared. We'll use the IDA function Jump to xref to operand
and we'll look for where the value is being assigned.
Here we can see that the pointer stored at word_31F50
is a pointer to a memory area equal to the # of lines on the system * 1200. We can assume that this is most likely a data area dedicated to storing user information for each potential user on each line (assuming each user was in LORD at the same time).
We'll go ahead and rename these two variables to userDataOff
and userDataSeg
. Knowing this, we now know that the previously referenced block of code in the btuchi()
routine is assigning a pointer to the current users data segment within userData
. 👍 Knowing all this, we can now decode what's happening in this code block.
It's loading the current users region of memory inside LORD and checking the value of the word (16-bit integer) located at 0x3BC and taking different actions based on the value.
Let's take a look at our debug output to see what MBBSEmu did:
2020-08-16 12:24:54.4044 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1433 mov ax,[bp+6] 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0000 BX=9AE2 CX=000D DX=0100 DS=0005 ES=FFFF 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=1436 SP=FFE6 BP=FFF1 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters CpzSo 2020-08-16 12:24:54.4044 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1436 imul ax,4B0h 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0000 BX=9AE2 CX=000D DX=0100 DS=0005 ES=FFFF 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=143A SP=FFE6 BP=FFF1 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters CpzSo 2020-08-16 12:24:54.4044 Debug MBBSEmu.CPU.CpuCore.Tick 0002:143A mov dx,ds:[9D12h] 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0000 BX=9AE2 CX=000D DX=0100 DS=0005 ES=FFFF 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=143E SP=FFE6 BP=FFF1 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters CpzSo 2020-08-16 12:24:54.4044 Debug MBBSEmu.CPU.CpuCore.Tick 0002:143E mov bx,ds:[9D10h] 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0000 BX=9AE2 CX=000D DX=0100 DS=0005 ES=FFFF 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=1442 SP=FFE6 BP=FFF1 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters CpzSo 2020-08-16 12:24:54.4044 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1442 add bx,ax 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0000 BX=9AE2 CX=000D DX=0100 DS=0005 ES=FFFF 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=1444 SP=FFE6 BP=FFF1 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters cpzSo 2020-08-16 12:24:54.4044 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1444 mov [bp-2],dx 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0000 BX=9AE2 CX=000D DX=0100 DS=0005 ES=FFFF 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=1447 SP=FFE6 BP=FFF1 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters cpzSo 2020-08-16 12:24:54.4044 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1447 mov [bp-4],bx 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0000 BX=9AE2 CX=000D DX=0100 DS=0005 ES=FFFF 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=144A SP=FFE6 BP=FFF1 2020-08-16 12:24:54.4044 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters cpzSo 2020-08-16 12:24:54.4044 Debug MBBSEmu.CPU.CpuCore.Tick 0002:144A les bx,[bp-4] 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0000 BX=9AE2 CX=000D DX=0100 DS=0005 ES=0100 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=144D SP=FFE6 BP=FFF1 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters cpzSo 2020-08-16 12:24:54.4200 Debug MBBSEmu.CPU.CpuCore.Tick 0002:144D mov ax,es:[bx+3BCh] 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0001 BX=9AE2 CX=000D DX=0100 DS=0005 ES=0100 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=1452 SP=FFE6 BP=FFF1 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters cpzSo 2020-08-16 12:24:54.4200 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1452 or ax,ax 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0001 BX=9AE2 CX=000D DX=0100 DS=0005 ES=0100 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=1454 SP=FFE6 BP=FFF1 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters cpzso 2020-08-16 12:24:54.4200 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1454 je short 1462h 2020-08-16 12:24:54.4200 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1456 cmp ax,1 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0001 BX=9AE2 CX=000D DX=0100 DS=0005 ES=0100 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=1459 SP=FFE6 BP=FFF1 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters cpZso 2020-08-16 12:24:54.4200 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1459 je short 1462h
We can see in the debug output that the value of the word loaded from bx+0x3BC
was 1
, which set the Z
flag and caused a jump on the subsequent JE
.
This next section explains how LORD handles user input on MajorBBS/Worldgroup. The value entered by the user is saved to their currentUserData
, and then the character entered (regardless of what the actual character was), is changed to 0xD
(Carriage Return).
2020-08-16 12:24:54.4200 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1462 les bx,[bp-4] 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0001 BX=9AE2 CX=000D DX=0100 DS=0005 ES=0100 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=1465 SP=FFE6 BP=FFF1 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters cpZso 2020-08-16 12:24:54.4200 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1465 mov es:[bx+261h],cl 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0001 BX=9AE2 CX=000D DX=0100 DS=0005 ES=0100 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=146A SP=FFE6 BP=FFF1 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters cpZso 2020-08-16 12:24:54.4200 Debug MBBSEmu.CPU.CpuCore.Tick 0002:146A mov cx,0Dh 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=0001 BX=9AE2 CX=000D DX=0100 DS=0005 ES=0100 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=146D SP=FFE6 BP=FFF1 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters cpZso 2020-08-16 12:24:54.4200 Debug MBBSEmu.CPU.CpuCore.Tick 0002:146D jmp short 147Dh 2020-08-16 12:24:54.4200 Debug MBBSEmu.CPU.CpuCore.Tick 0002:147D mov al,cl 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=000D BX=9AE2 CX=000D DX=0100 DS=0005 ES=0100 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=147F SP=FFE6 BP=FFF1 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters cpZso 2020-08-16 12:24:54.4200 Debug MBBSEmu.CPU.CpuCore.Tick 0002:147F pop ds 2020-08-16 12:24:54.4200 Info MBBSEmu.CPU.CpuCore.Pop Popped 0000 from FFE7 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=000D BX=9AE2 CX=000D DX=0100 DS=0000 ES=0100 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=1480 SP=FFE8 BP=FFF1 2020-08-16 12:24:54.4200 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters cpZso 2020-08-16 12:24:54.4374 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1480 pop di 2020-08-16 12:24:54.4374 Info MBBSEmu.CPU.CpuCore.Pop Popped 0000 from FFE9 2020-08-16 12:24:54.4374 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=000D BX=9AE2 CX=000D DX=0100 DS=0000 ES=0100 2020-08-16 12:24:54.4374 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=1481 SP=FFEA BP=FFF1 2020-08-16 12:24:54.4374 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters cpZso 2020-08-16 12:24:54.4374 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1481 pop si 2020-08-16 12:24:54.4374 Info MBBSEmu.CPU.CpuCore.Pop Popped 0000 from FFEB 2020-08-16 12:24:54.4374 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=000D BX=9AE2 CX=000D DX=0100 DS=0000 ES=0100 2020-08-16 12:24:54.4374 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=1482 SP=FFEC BP=FFF1 2020-08-16 12:24:54.4374 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters cpZso 2020-08-16 12:24:54.4374 Debug MBBSEmu.CPU.CpuCore.Tick 0002:1482 leave 2020-08-16 12:24:54.4374 Info MBBSEmu.CPU.CpuCore.Pop Popped FFF7 from FFF2 2020-08-16 12:24:54.4374 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters AX=000D BX=9AE2 CX=000D DX=0100 DS=0000 ES=0100 2020-08-16 12:24:54.4374 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters SI=0000 DI=0000 SS=0000 IP=1483 SP=FFF3 BP=FFF7 2020-08-16 12:24:54.4374 Info MBBSEmu.Logging.LoggerExtension.InfoRegisters cpZso
Result
The result from the registered btuchi()
function in LORD is:
- Character value is <= 127
- Character is set to
*
if special cases are detected - Entered character is saved to the User's designated memory within LORD
- Entered character is changed to
0xD
(Carriage Return) regardless of input
The changing of the input to Carriage Return results in the sttrou()
routine to be triggered within MajorBBS/Worldgroup, as IF you hit enter (on every character). This is how RTSLORD
handles single character menu navigation without having to resort to using any of the built in polling/event methods within MajorBBS/Worldgroup.