Common log format

Reply 40 of 90, by superfury

Posted on 2017-10-21, 12:00

superfury Offline

Rank l33t++

Rank: l33t++
Posts: 5455
Joined: 2014-03-08, 11:25
Location: Netherlands

I've just added a simple option to use IPS(Instructions per Second) clocking instead of the cycle-accurate clock. It should make it easier to compare between the emulators, since cycle-accurate clocking will have the effect of using completely different execution paths, depending on various cycle differences? (Hardware timing, CPU timing, DMA timing etc.)

What this new option I've implemented does is the following:
- The default cycle count is changed from the cycle-accurate timing to 3000 IPS cycles(1 IPS cycles speed is 1000 instructions per second, so it's Dosbox's default speed).
- Hardware(including DMA) and realtime synchronization is timed by executed status(instruction finished executing or not). The CPU itself is unmodified and executes in it's usual cycle-accurate method internally.
- DMA doesn't take the BUS from the CPU anymore. Instead it assumes full control over the BUS always(the same applies to the CPU, since it never has control taken from it). SI(and S1) always follows S4, since the BUS is always assumed to be freed after S4 and at SI.

That way, it becomes fully IPS-compliant, allowing for a comparision without requiring cycle-accuracy(since everything is timed using instruction clocks only instead of cycle clocking, which may vary between emulators).

Your ideas on this take?

Author of the UniPCemu emulator.
UniPCemu Git repository
UniPCemu for Android, Windows, PSP, Vita and Switch on itch.io

Reply 41 of 90, by vladstamate

Posted on 2017-10-21, 22:20

vladstamate Offline

Rank Oldbie

Rank: Oldbie
Posts: 967
Joined: 2015-08-23, 01:43

I think that might work. If time only passes when you retire an instruction.

However, how do you solve the IPS given that our emulators would take longer (in actual real time) to emulate an IMUL as opposed to an XOR (should be 10x longer)? How do you have a constant IPS when exeuting instructions for which the emulation time is not constant? Remember our emulators don't simply have a big switch case with an "atomic" execution.

YouTube channel: https://www.youtube.com/channel/UC7HbC_nq8t1S9l7qGYL0mTA
Collection: http://www.digiloguemuseum.com/index.html
Emulator: https://sites.google.com/site/capex86/
Raytracer: https://sites.google.com/site/opaqueraytracer/

Reply 42 of 90, by superfury

Posted on 2017-10-22, 00:13

superfury Offline

Rank l33t++

Rank: l33t++
Posts: 5455
Joined: 2014-03-08, 11:25
Location: Netherlands

Simply a flag that indicates an intruction is finished instead of 1 cycle to spend(which during cycle accurate CPU emulation is usually a constant 1(cycle spent by the BIU)). Since it's only 1 when a instruction retires(the debugger can step/log the completed instruction in my emulator, I assume it's the same with yours?), I use that one to tick hardware 1 or 0 CPU cycles, instead of always 1 cycle. Of course using Dosbox clocks 3000 cycles means 3000000 IPS(since it's Instructions per ms).

Even though instructions take multiple cycles, instead of updating hardware each cycle, make it possible to only tick one CPU cycle worth of realtime(UniPCemu comverts the CPU cycles or IPS cycle(execution completed flag) to nanoseconds(time passed), then also converts that to 14MHz cycles for ISA devices. Either nanoseconds and/or 14MHz clock cycles is then sent to all hardware to update their internal clocks.

That ensures that the CPU can run in various clock speeds and modes(IPS vs cycles) while each hardware runs at it's own (comstant, if applicable) speed in parallel to the CPU.

1OPTINLINE byte coreHandler()
2{
3	uint_32 MHZ14passed; //14 MHZ clock passed?
4	byte BIOSMenuAllowed = 1; //Are we allowed to open the BIOS menu?
5	//CPU execution, needs to be before the debugger!
6	lock(LOCK_INPUT);
7	if (unlikely((haswindowactive&0x1C)==0xC)) {getnspassed(&CPU_timing); haswindowactive|=0x10;} //Pending to finish Soundblaster!
8	currenttiming += likely(haswindowactive&2)?getnspassed(&CPU_timing):0; //Check for any time that has passed to emulate! Don't emulate when not allowed to run, keeping emulation paused!
9	unlock(LOCK_INPUT);
10	uint_64 currentCPUtime = (uint_64)currenttiming; //Current CPU time to update to!
11	uint_64 timeoutCPUtime = currentCPUtime+TIMEOUT_TIME; //We're timed out this far in the future (1ms)!
12
13	double instructiontime,timeexecuted=0.0f; //How much time did the instruction last?
14	byte timeout = TIMEOUT_INTERVAL; //Check every 10 instructions for timeout!
15	for (;last_timing<currentCPUtime;) //CPU cycle loop for as many cycles as needed to get up-to-date!
16	{
17		if (debugger_thread)
18		{
19			if (threadRunning(debugger_thread)) //Are we running the debugger?
20			{
21				instructiontime = currentCPUtime - last_timing; //The instruction time is the total time passed!
22				updateAudio(instructiontime); //Discard the time passed!
23				timeexecuted += instructiontime; //Increase CPU executed time executed this block!
24				last_timing += instructiontime; //Increase the last timepoint!
25				goto skipCPUtiming; //OK, but skipped!
26			}
27		}
28		if (BIOSMenuThread)
29		{
30			if (threadRunning(BIOSMenuThread)) //Are we running the BIOS menu and not permanently halted? Block our execution!
31			{
32				if ((CPU[activeCPU].halt&2)==0) //Are we allowed to be halted entirely?
33				{
34					instructiontime = currentCPUtime - last_timing; //The instruction time is the total time passed!
35					updateAudio(instructiontime); //Discard the time passed!
36					timeexecuted += instructiontime; //Increase CPU executed time executed this block!
37					last_timing += instructiontime; //Increase the last timepoint!
38					goto skipCPUtiming; //OK, but skipped!
39				}
40				BIOSMenuAllowed = 0; //We're running the BIOS menu! Don't open it again!
41			}
42		}
43		if ((CPU[activeCPU].halt&2)==0) //Are we running normally(not partly ran without CPU from the BIOS menu)?
44		{
45			BIOSMenuThread = NULL; //We don't run the BIOS menu anymore!
46		}
47
48		if (allcleared) return 0; //Abort: invalid buffer!
49
50		interruptsaved = 0; //Reset PIC interrupt to not used!
51		if (!CPU[activeCPU].registers) //We need registers at this point, but have none to use?
52		{
53			return 0; //Invalid registers: abort, since we're invalid!
54		}
55
56		CPU_resetTimings(); //Reset all required CPU timings required!
57
58		CPU_tickPendingReset();
59
60		if ((CPU[activeCPU].halt&3) && (BIU_Ready() && CPU[activeCPU].resetPending==0)) //Halted normally with no reset pending? Don't count CGA wait states!

…Show last 193 lines

61		{
62			if (romsize) //Debug HLT?
63			{
64				MMU_dumpmemory("bootrom.dmp"); //Dump the memory to file!
65				return 0; //Stop execution!
66			}
67
68			if (FLAG_IF && PICInterrupt() && ((CPU[activeCPU].halt&2)==0)) //We have an interrupt? Clear Halt State when allowed to!
69			{
70				CPU[activeCPU].halt = 0; //Interrupt->Resume from HLT
71				goto resumeFromHLT; //We're resuming from HLT state!
72			}
73			else
74			{
75				//Execute using actual CPU clocks!
76				CPU[activeCPU].cycles = 1; //HLT takes 1 cycle for now, since it's unknown!
77			}
78			if (CPU[activeCPU].halt==1) //Normal halt?
79			{
80				//Increase the instruction counter every instruction/HLT time!
81				cpudebugger = needdebugger(); //Debugging information required? Refresh in case of external activation!
82				if (cpudebugger) //Debugging?
83				{
84					debugger_beforeCPU(); //Make sure the debugger is prepared when needed!
85					debugger_setcommand("<HLT>"); //We're a HLT state, so give the HLT command!
86				}
87				CPU[activeCPU].executed = 1; //For making the debugger execute correctly!
88				//Increase the instruction counter every cycle/HLT time!
89				debugger_step(); //Step debugger if needed, even during HLT state!
90			}
91		}
92		else //We're not halted? Execute the CPU routines!
93		{
94			resumeFromHLT:
95			if (CPU[activeCPU].instructionfetch.CPU_isFetching && (CPU[activeCPU].instructionfetch.CPU_fetchphase==1)) //We're starting a new instruction?
96			{
97				if (CPU[activeCPU].registers && doEMUsinglestep && allow_debuggerstep) //Single step enabled and allowed?
98				{
99					if (getcpumode() == (doEMUsinglestep - 1)) //Are we the selected CPU mode?
100					{
101						switch (getcpumode()) //What CPU mode are we to debug?
102						{
103						case CPU_MODE_REAL: //Real mode?
104							singlestep |= ((CPU[activeCPU].registers->CS == (((singlestepaddress >> 16)&0xFFFF)) && ((CPU[activeCPU].registers->IP == (singlestepaddress & 0xFFFF))||(singlestepaddress&0x1000000000000ULL)))||(singlestepaddress&0x2000000000000ULL)); //Single step enabled?
105							break;
106						case CPU_MODE_PROTECTED: //Protected mode?
107						case CPU_MODE_8086: //Virtual 8086 mode?
108							singlestep |= ((CPU[activeCPU].registers->CS == (((singlestepaddress >> 32)&0xFFFF)) && ((CPU[activeCPU].registers->EIP == (singlestepaddress & 0xFFFFFFFF))||(singlestepaddress&0x1000000000000ULL)))||(singlestepaddress&0x2000000000000ULL)); //Single step enabled?
109							break;
110						default: //Invalid mode?
111							break;
112						}
113					}
114				}
115
116				cpudebugger = needdebugger(); //Debugging information required? Refresh in case of external activation!
117				MMU_logging = debugger_logging(); //Are we logging?
118
119				HWINT_saved = 0; //No HW interrupt by default!
120				CPU_beforeexec(); //Everything before the execution!
121				if ((!CPU[activeCPU].trapped) && CPU[activeCPU].registers && CPU[activeCPU].allowInterrupts && (CPU[activeCPU].permanentreset==0) && (CPU[activeCPU].internalinterruptstep==0) && BIU_Ready() && (CPU_executionphase_busy()==0)) //Only check for hardware interrupts when not trapped and allowed to execute interrupts(not permanently reset)!
122				{
123					if (FLAG_IF) //Interrupts available?
124					{
125						if (PICInterrupt()) //We have a hardware interrupt ready?
126						{
127							HWINT_nr = nextintr(); //Get the HW interrupt nr!
128							HWINT_saved = 2; //We're executing a HW(PIC) interrupt!
129							if (!((EMULATED_CPU <= CPU_80286) && REPPending)) //Not 80386+, REP pending and segment override?
130							{
131								CPU_8086REPPending(); //Process pending REPs normally as documented!
132							}
133							else //Execute the CPU bug!
134							{
135								CPU_8086REPPending(); //Process pending REPs normally as documented!
136								CPU[activeCPU].registers->EIP = CPU_InterruptReturn; //Use the special interrupt return address to return to the last prefix instead of the start!
137							}
138							CPU_exec_lastCS = CPU_exec_CS;
139							CPU_exec_lastEIP = CPU_exec_EIP;
140							CPU_exec_CS = CPU[activeCPU].registers->CS; //Save for error handling!
141							CPU_exec_EIP = CPU[activeCPU].registers->EIP; //Save for error handling!
142							CPU_saveFaultData(); //Save fault data to go back to when exceptions occur!
143							call_hard_inthandler(HWINT_nr); //get next interrupt from the i8259, if any!
144						}
145					}
146				}
147
148				#ifdef LOG_BOGUS
149				uint_32 addr_start, addr_left, curaddr; //Start of the currently executing instruction in real memory! We're testing 5 instructions!
150				addr_left=2*LOG_BOGUS;
151				curaddr = 0;
152				addr_start = CPU_MMU_start(CPU_SEGMENT_CS,CPU[activeCPU].registers->CS); //Base of the currently executing block!
153				addr_start += REG_EIP; //Add the address for the address we're executing!
154			
155				for (;addr_left;++curaddr) //Test all addresses!
156				{
157					if (MMU_directrb_realaddr(addr_start+curaddr)) //Try to read the opcode! Anything found(not 0000h instruction)?
158					{
159						break; //Stop searching!
160					}
161					--addr_left; //Tick one address checked!
162				}
163				if (addr_left==0) //Bogus memory detected?
164				{
165					dolog("bogus","Bogus exection memory detected(%u 0000h opcodes) at %04X:%08X! Previous instruction: %02X(0F:%u)@%04X:%08X",LOG_BOGUS,CPU[activeCPU].registers->CS,CPU[activeCPU].registers->EIP,CPU[activeCPU].previousopcode,CPU[activeCPU].previousopcode0F,CPU_exec_lastCS,CPU_exec_lastEIP); //Log the warning of entering bogus memory!
166				}
167				#endif
168			}
169
170			CPU_exec(); //Run CPU!
171
172			//Increase the instruction counter every cycle/HLT time!
173			debugger_step(); //Step debugger if needed!
174			if (CPU[activeCPU].executed) //Are we executed?
175			{
176				CB_handleCallbacks(); //Handle callbacks after CPU/debugger usage!
177			}
178		}
179
180		//Update current timing with calculated cycles we've executed!
181		if (likely(useIPSclock==0)) //Use cycle-accurate clock?
182		{
183			instructiontime = CPU[activeCPU].cycles*CPU_speed_cycle; //Increase timing with the instruction time!
184		}
185		else
186		{
187			instructiontime = CPU[activeCPU].executed*CPU_speed_cycle; //Increase timing with the instruction time!
188		}
189		last_timing += instructiontime; //Increase CPU time executed!
190		timeexecuted += instructiontime; //Increase CPU executed time executed this block!
191
192		//Tick 14MHz master clock, for basic hardware using it!
193		MHZ14_ticktiming += instructiontime; //Add time to the 14MHz master clock!
194		if (likely(MHZ14_ticktiming<MHZ14tick)) //To not tick some 14MHz clocks? This ix the case with most faster CPUs!
195		{
196			MHZ14passed = 0; //No time has passed on the 14MHz Master clock!
197		}
198		else
199		{
200			MHZ14passed = (uint_32)(MHZ14_ticktiming/MHZ14tick); //Tick as many as possible!
201			MHZ14_ticktiming -= MHZ14tick*(float)MHZ14passed; //Rest the time passed!
202		}
203
204		MMU_logging |= 2; //Are we logging hardware memory accesses(DMA etc)?
205		if (likely((CPU[activeCPU].halt&0x10)==0)) tickPIT(instructiontime,MHZ14passed); //Tick the PIT as much as we need to keep us in sync when running!
206		updateDMA(MHZ14passed); //Update the DMA timer!
207		updateMouse(instructiontime); //Tick the mouse timer if needed!
208		stepDROPlayer(instructiontime); //DRO player playback, if any!
209		updateMIDIPlayer(instructiontime); //MIDI player playback, if any!
210		updatePS2Keyboard(instructiontime); //Tick the PS/2 keyboard timer, if needed!
211		updatePS2Mouse(instructiontime); //Tick the PS/2 mouse timer, if needed!
212		update8042(instructiontime); //Tick the PS/2 mouse timer, if needed!
213		updateCMOS(instructiontime); //Tick the CMOS, if needed!
214		updateFloppy(instructiontime); //Update the floppy!
215		updateMPUTimer(instructiontime); //Update the MPU timing!
216		if (useAdlib) updateAdlib(MHZ14passed); //Tick the adlib timer if needed!
217		if (useGameBlaster && ((CPU[activeCPU].halt&0x10)==0)) updateGameBlaster(instructiontime,MHZ14passed); //Tick the Game Blaster timer if needed and running!
218		if (useSoundBlaster && ((CPU[activeCPU].halt&0x10)==0)) updateSoundBlaster(instructiontime,MHZ14passed); //Tick the Sound Blaster timer if needed and running!
219		updateATA(instructiontime); //Update the ATA timer!
220		tickParallel(instructiontime); //Update the Parallel timer!
221		updateUART(instructiontime); //Update the UART timer!
222		if (useLPTDAC && ((CPU[activeCPU].halt&0x10)==0)) tickssourcecovox(instructiontime); //Update the Sound Source / Covox Speech Thing if needed!
223		if (likely((CPU[activeCPU].halt&0x10)==0)) updateVGA(instructiontime); //Update the VGA timer when running!
224		updateModem(instructiontime); //Update the modem!
225		updateJoystick(instructiontime); //Update the Joystick!
226		updateAudio(instructiontime); //Update the general audio processing!
227		BIOSROM_updateTimers(instructiontime); //Update any ROM(Flash ROM) timers!
228		MMU_logging &= ~2; //Are we logging hardware memory accesses again?
229		if (--timeout==0) //Timed out?
230		{
231			timeout = TIMEOUT_INTERVAL; //Reset the timeout to check the next time!
232			currenttiming += getnspassed(&CPU_timing); //Check for passed time!
233			if (currenttiming >= timeoutCPUtime) break; //Timeout? We're not fast enough to run at full speed!
234		}
235	} //CPU cycle loop!
236
237	skipCPUtiming: //Audio emulation only?
238	//Slowdown to requested speed if needed!
239	currenttiming += getnspassed(&CPU_timing); //Add real time!
240	for (;currenttiming < last_timing;) //Not enough time spent on instructions?
241	{
242		currenttiming += getnspassed(&CPU_timing); //Add to the time to wait!
243		delay(0); //Update to current time every instruction according to cycles passed!
244	}
245
246	float temp;
247	temp = (float)MAX(last_timing,currenttiming); //Save for substraction(time executed in real time)!
248	last_timing -= temp; //Keep the CPU timing within limits!
249	currenttiming -= temp; //Keep the current timing within limits!
250
251	timeemulated += timeexecuted; //Add timing for the CPU percentage to update!
252
253	updateKeyboard(timeexecuted); //Tick the keyboard timer if needed!

That's UniPCemu's main execution loop. The CPU_exec updates EU and BIU for 1 cycle. Can't the same kind of loop method be used with your emulators?

Last edited by superfury on 2017-10-26, 08:46. Edited 1 time in total.

Author of the UniPCemu emulator.
UniPCemu Git repository
UniPCemu for Android, Windows, PSP, Vita and Switch on itch.io

Reply 43 of 90, by superfury

Posted on 2017-10-26, 08:44

superfury Offline

Rank l33t++

Rank: l33t++
Posts: 5455
Joined: 2014-03-08, 11:25
Location: Netherlands

I'm just thinking, shouldn't we add some kind of register dump/memory accesses to the logs? That way we can see exactly what goes wrong when executing instruction, instead of just execution path? UniPCemu can already log those, but it's currently disabled for the common log format(since we haven't gotten to those yet).

Author of the UniPCemu emulator.
UniPCemu Git repository
UniPCemu for Android, Windows, PSP, Vita and Switch on itch.io

Reply 44 of 90, by vladstamate

Posted on 2017-10-26, 14:11

vladstamate Offline

Rank Oldbie

Rank: Oldbie
Posts: 967
Joined: 2015-08-23, 01:43

Yes, absolutely. This is what I have and I am happy to change to have something we are all happy with.

1EAX: 0x00008000 EBX: 0x000006f8 ECX: 0x00000000 EDX: 0x00000190
2ESP: 0x00007ff8 EBP: 0x00001000 ESI: 0x00000000 EDI: 0x00000000
3SS: 0x0000 DS: 0x0000 ES: 0x8000 CS: 0x0000
4EIP: 0x000094a6
5CF: 0 PF: 1 AF: 0 ZF: 0 SF: 0 TF: 0 IF: 0 DF: 0 OF: 0

NOTE 1: this should be a toggle though, you do not always want register dump on
NOTE 2: I admit the flags are not displayed as well as they should. For once, I am missing some and two: they should be displayed the other way around (CF is least significant bit).
NOTE 3: this should work for 16bit processors too (8088, 80286, etc) just that top 16bit of the 32bit registers (e.g. EAX) will be 0
NOTE 4: this is also missing CR registers.

YouTube channel: https://www.youtube.com/channel/UC7HbC_nq8t1S9l7qGYL0mTA
Collection: http://www.digiloguemuseum.com/index.html
Emulator: https://sites.google.com/site/capex86/
Raytracer: https://sites.google.com/site/opaqueraytracer/

Reply 45 of 90, by superfury

Posted on 2017-10-26, 16:30

superfury Offline

Rank l33t++

Rank: l33t++
Posts: 5455
Joined: 2014-03-08, 11:25
Location: Netherlands

This is what I currently use with UniPCemu(it logs all registers as well as some extra state info such as HLT and reset(first instruction after the CPU has been reset) status):

1OPTINLINE char decodeHLTreset(byte halted,byte isreset)
2{
3	if (halted)
4	{
5		return 'H'; //We're halted!
6	}
7	else if (isreset)
8	{
9		if (isreset&2) //Permanently reset?
10		{
11			return '*'; //We're permanently reset!
12		}
13		//Normal reset?
14		return 'R'; //We're reset!
15	}
16	return ' '; //Nothing to report, give empty!
17}
18
19void debugger_logregisters(char *filename, CPU_registers *registers, byte halted, byte isreset)
20{
21	if ((DEBUGGER_LOG==DEBUGGERLOG_ALWAYS_COMMONLOGFORMAT) || (DEBUGGER_LOG==DEBUGGERLOG_ALWAYS_DURINGSKIPSTEP_COMMONLOGFORMAT) || (DEBUGGER_LOG==DEBUGGERLOG_DEBUGGING_COMMONLOGFORMAT)) //Common log format?
22	{
23		return; //No register logging, we're disabled for now!
24	}
25	if ((DEBUGGER_LOG==DEBUGGERLOG_ALWAYS_NOREGISTERS) || (DEBUGGER_LOG==DEBUGGERLOG_ALWAYS_SINGLELINE) || (DEBUGGER_LOG==DEBUGGERLOG_DEBUGGING_SINGLELINE) || (DEBUGGER_LOG==DEBUGGERLOG_ALWAYS_SINGLELINE_SIMPLIFIED) || (DEBUGGER_LOG==DEBUGGERLOG_DEBUGGING_SINGLELINE_SIMPLIFIED)) return; //Don't log the register state?
26	if (!registers || !filename) //Invalid?
27	{
28		log_timestampbackup = log_logtimestamp(2); //Save state!
29		log_logtimestamp(debugger_loggingtimestamp); //Are we to log the timestamp?
30		dolog(filename,"Log registers called with invalid argument!");
31		log_logtimestamp(log_timestampbackup); //Restore state!
32		return; //Abort!
33	}
34	log_timestampbackup = log_logtimestamp(2); //Save state!
35	log_logtimestamp(debugger_loggingtimestamp); //Are we to log the timestamp?
36	if (EMULATED_CPU<=CPU_80286) //Emulating 80(1)86 registers?
37	{
38		#ifndef LOGFLAGSONLY
39		dolog(filename,"Registers:"); //Start of the registers!
40		dolog(filename,"AX: %04X, BX: %04X, CX: %04X, DX: %04X",registers->AX,registers->BX,registers->CX,registers->DX); //Basic registers!
41		if (registers->CR0&1) //Protected mode?
42		{
43			dolog(filename,"CS: %04X, DS: %04X, ES: %04X, SS: %04X, TR: %04X, LDTR:%04X",registers->CS,registers->DS,registers->ES,registers->SS,registers->TR,registers->LDTR); //Segment registers!
44		}
45		else //Real mode?
46		{
47			dolog(filename,"CS: %04X, DS: %04X, ES: %04X, SS: %04X",registers->CS,registers->DS,registers->ES,registers->SS); //Segment registers!
48		}
49		dolog(filename,"SP: %04X, BP: %04X, SI: %04X, DI: %04X",registers->SP,registers->BP,registers->SI,registers->DI); //Segment registers!
50		dolog(filename,"IP: %04X, FLAGS: %04X",registers->IP,registers->FLAGS); //Rest!
51		if (EMULATED_CPU==CPU_80286) //80286 has CR0 as well?
52		{
53			dolog(filename, "CR0: %04X", (registers->CR0&0xFFFF)); //Rest!
54			dolog(filename,"GDTR: " LONGLONGSPRINTX ", IDTR: " LONGLONGSPRINTX,(LONG64SPRINTF)registers->GDTR.data,(LONG64SPRINTF)registers->IDTR.data); //GDTR/IDTR!
55		}
56		#endif
57		dolog(filename,"FLAGSINFO:%s%c",debugger_generateFlags(registers),decodeHLTreset(halted,isreset)); //Log the flags!
58		//More aren't implemented in the 80(1/2)86!
59	}
60	else //80386+? 32-bit registers!

…Show last 37 lines

61	{
62		dolog(filename,"Registers:"); //Start of the registers!
63		#ifndef LOGFLAGSONLY
64		dolog(filename,"EAX: %08x, EBX: %08x, ECX: %08x, EDX: %08x",registers->EAX,registers->EBX,registers->ECX,registers->EDX); //Basic registers!
65		
66		if (registers->CR0&1) //Protected mode?
67		{
68			dolog(filename,"CS: %04X, DS: %04X, ES: %04X, FS: %04X, GS: %04X SS: %04X, TR: %04X, LDTR:%04X",registers->CS,registers->DS,registers->ES,registers->FS,registers->GS,registers->SS,registers->TR,registers->LDTR); //Segment registers!
69		}
70		else //Real mode?
71		{
72			dolog(filename,"CS: %04X, DS: %04X, ES: %04X, FS: %04X, GS: %04X SS: %04X",registers->CS,registers->DS,registers->ES,registers->FS,registers->GS,registers->SS); //Segment registers!
73		}
74
75		dolog(filename,"ESP: %08x, EBP: %08x, ESI: %08x, EDI: %08x",registers->ESP,registers->EBP,registers->ESI,registers->EDI); //Segment registers!
76		dolog(filename,"EIP: %08x, EFLAGS: %08x",registers->EIP,registers->EFLAGS); //Rest!
77		
78		dolog(filename, "CR0: %08X; CR1: %08X; CR2: %08X; CR3: %08X", registers->CR0, registers->CR1, registers->CR2, registers->CR3); //Rest!
79		dolog(filename, "CR4: %08X; CR5: %08X; CR6: %08X; CR7: %08X", registers->CR4, registers->CR5, registers->CR6, registers->CR7); //Rest!
80
81		dolog(filename, "DR0: %08X; DR1: %08X; DR2: %08X; CR3: %08X", registers->DR0, registers->DR1, registers->DR2, registers->DR3); //Rest!
82		if (EMULATED_CPU>=CPU_PENTIUM) //Pentium has DR4?
83		{
84			dolog(filename, "DR4: %08X; DR6: %08X; DR5&7: %08X", registers->DR4, registers->DR6, registers->DR7); //Rest!
85		}
86		else //DR4=>DR6
87		{
88			dolog(filename, "DR6: %08X; DR5&7: %08X", registers->DR6, registers->DR7); //Rest!
89		}
90
91		dolog(filename,"GDTR: " LONGLONGSPRINTX ", IDTR: " LONGLONGSPRINTX,(LONG64SPRINTF)registers->GDTR.data,(LONG64SPRINTF)registers->IDTR.data); //GDTR/IDTR!
92		#endif
93		//Finally, flags seperated!
94		dolog(filename,"FLAGSINFO:%s%c",debugger_generateFlags(registers),(char)(halted?'H':' ')); //Log the flags!
95	}
96	log_logtimestamp(log_timestampbackup); //Restore state!
97}

So in the common case, 80386+ behaviour would be forced instead of CPU-dependent. I would have to move ESP/EBP/ESI/EDI up a bit. Also, protected-mode-only registers aren't logged in real mode(unaccessable by software, might contain junk on real CPU). Seperate flags are formatted as Upper case(Set supported flag)/lower case(Cleared supported flag)/0(unknown cleared)/1(unknown set) letters and numbers, depending on CPU support(supported vs unsupported bits).

1char flags[256]; //Flags as a text!
2static char *debugger_generateFlags(CPU_registers *registers)
3{
4	strcpy(flags,""); //Clear the flags!
5	sprintf(flags,"%s%c",flags,(char)(FLAGREGR_CF(registers)?'C':'c'));
6	sprintf(flags,"%s%u",flags,FLAGREGR_UNMAPPED2(registers));
7	sprintf(flags,"%s%c",flags,(char)(FLAGREGR_PF(registers)?'P':'p'));
8	sprintf(flags,"%s%u",flags,FLAGREGR_UNMAPPED8(registers));
9	sprintf(flags,"%s%c",flags,(char)(FLAGREGR_AF(registers)?'A':'a'));
10	sprintf(flags,"%s%u",flags,FLAGREGR_UNMAPPED32(registers));
11	sprintf(flags,"%s%c",flags,(char)(FLAGREGR_ZF(registers)?'Z':'z'));
12	sprintf(flags,"%s%c",flags,(char)(FLAGREGR_SF(registers)?'S':'s'));
13	sprintf(flags,"%s%c",flags,(char)(FLAGREGR_TF(registers)?'T':'t'));
14	sprintf(flags,"%s%c",flags,(char)(FLAGREGR_IF(registers)?'I':'i'));
15	sprintf(flags,"%s%c",flags,(char)(FLAGREGR_DF(registers)?'D':'d'));
16	sprintf(flags,"%s%c",flags,(char)(FLAGREGR_OF(registers)?'O':'o'));
17	if (EMULATED_CPU>=CPU_80286) //286+?
18	{
19		sprintf(flags,"%s%u",flags,(word)(FLAGREGR_IOPL(registers)&1));
20		sprintf(flags,"%s%u",flags,(word)((FLAGREGR_IOPL(registers)&2)>>1));
21		sprintf(flags,"%s%c",flags,(char)(FLAGREGR_NT(registers)?'N':'n'));
22	}
23	else //186-? Display as numbers!
24	{
25		sprintf(flags,"%s%u",flags,(word)(FLAGREGR_IOPL(registers)&1));
26		sprintf(flags,"%s%u",flags,(word)((FLAGREGR_IOPL(registers)&2)>>1));
27		sprintf(flags,"%s%u",flags,FLAGREGR_NT(registers));
28	}
29	//Higest 16-bit value!
30	sprintf(flags,"%s%u",flags,FLAGREGR_UNMAPPED32768(registers));
31	
32	//Now the high word (80386+)!
33	if (EMULATED_CPU>=CPU_80386) //386+?
34	{
35		sprintf(flags,"%s%c",flags,(char)(FLAGREGR_RF(registers)?'R':'r'));
36		sprintf(flags,"%s%c",flags,(char)(FLAGREGR_V8(registers)?'V':'v'));
37		if (EMULATED_CPU>=CPU_80486) //486+?
38		{
39			sprintf(flags,"%s%c",flags,(char)(FLAGREGR_AC(registers)?'A':'a'));
40		}
41		else //386?
42		{
43			sprintf(flags,"%s%u",flags,FLAGREGR_AC(registers)); //Literal bit!
44		}
45		if (EMULATED_CPU>=CPU_PENTIUM) //Pentium+?
46		{
47			sprintf(flags,"%s%c",flags,(char)(FLAGREGR_VIF(registers)?'F':'f'));
48			sprintf(flags,"%s%c",flags,(char)(FLAGREGR_VIP(registers)?'P':'p'));
49			sprintf(flags,"%s%c",flags,(char)(FLAGREGR_ID(registers)?'I':'i'));
50		}
51		else //386/486?
52		{
53			sprintf(flags,"%s%u",flags,FLAGREGR_VIF(registers));
54			sprintf(flags,"%s%u",flags,FLAGREGR_VIP(registers));
55			sprintf(flags,"%s%u",flags,FLAGREGR_ID(registers));
56		}
57		//Unmapped high bits!
58		int i; //For counting the current bit!
59		word j; //For holding the current bit!
60		j = 1; //Start with value 1!

…Show last 15 lines

61		for (i=0;i<10;i++) //10-bits value rest!
62		{
63			if (FLAGREGR_UNMAPPEDHI(registers)&j) //Bit set?
64			{
65				sprintf(flags,"%s1",flags); //1!
66			}
67			else //Bit cleared?
68			{
69				sprintf(flags,"%s0",flags); //0!
70			}
71			j <<= 1; //Shift to the next bit!
72		}
73	}
74	return &flags[0]; //Give the flags for quick reference!
75}

Another thing that would be needed is memory accesses themselves. UniPCemu just logs bytes accessed in three level format(direction of nesting used for the result): logical -> linear -> physical -> RAM. Logical, linear and RAM layer being dependant on the start/endpoint(no RAM for hardware, no linear/logical for Paging TLB retrieval(CR3 tables) from RAM, No logical for GDT/IDT/LDT fetches.

The start of the memory accesses is the first of those that's used during writes, but the last of those during reads(you can't log what you've read from logical/linear/physical before the RAM/hardware responds with something that's been read from it(and logs it's layer of access). The BIU always starts at the physical layer in UniPCemu(it directly accesses the hardware/RAM layer(hardware has priority over RAM). According to the profiler, that layer is the most CPU-heavy of the entire CPU emulation, probably because it requests for all hardware to respond before falling back to RAM(Using a registered hardware loop for every accessed byte).

Author of the UniPCemu emulator.
UniPCemu Git repository
UniPCemu for Android, Windows, PSP, Vita and Switch on itch.io

Reply 46 of 90, by vladstamate

Posted on 2017-10-26, 17:56

vladstamate Offline

Rank Oldbie

Rank: Oldbie
Posts: 967
Joined: 2015-08-23, 01:43

So if I understand correctly

For 286 and below you show 16 bit registers
For 386 and above you show 32 bit registers
For 386 you also show CR and DR registers.

NOTE: 386 only has CR0-CR3 ( I assume you display CR4+ because you emulate something higher?)

NOTE 2: can we show GDTR, IDTR and LDTR regardless if we are in PM or not? They exist for 286+, whether they are used or not is a different consideration.

NOTE 3: same goes for FS/GS in 386+. Show they always. They can be used outside PM, you only display them in PM.

Basically if a register is present in that architecture show it.

YouTube channel: https://www.youtube.com/channel/UC7HbC_nq8t1S9l7qGYL0mTA
Collection: http://www.digiloguemuseum.com/index.html
Emulator: https://sites.google.com/site/capex86/
Raytracer: https://sites.google.com/site/opaqueraytracer/

Reply 47 of 90, by superfury

Posted on 2017-10-26, 18:47

superfury Offline

Rank l33t++

Rank: l33t++
Posts: 5455
Joined: 2014-03-08, 11:25
Location: Netherlands

Got a good point there about showing all registers, they have values after all(initialized to zeroes by default/reset). Although real mode can't use some of them(LDTR, TR). Forgot about FS/GS: You're right about those.

Author of the UniPCemu emulator.
UniPCemu Git repository
UniPCemu for Android, Windows, PSP, Vita and Switch on itch.io

Reply 48 of 90, by superfury

Posted on 2017-10-26, 20:19

superfury Offline

Rank l33t++

Rank: l33t++
Posts: 5455
Joined: 2014-03-08, 11:25
Location: Netherlands

I've imptoved the logging, not requiring protected mode and only depending on the CPU when logging:

1F000:0000FFF0 EA 45 00 00 F0 jmp f000:00000045
2Registers:
3EAX: 00000000, EBX: 00000000, ECX: 00000000, EDX: 00000308
4ESP: 00000000, EBP: 00000000, ESI: 00000000, EDI: 00000000
5CS: F000, DS: 0000, ES: 0000, FS: 0000, GS: 0000 SS: 0000, TR: 0000, LDTR:0000
6EIP: 0000fff0, EFLAGS: 00000002
7CR0: 00000000; CR1: 00000000; CR2: 00000000; CR3: 00000000
8DR0: 00000000; DR1: 00000000; DR2: 00000000; CR3: 00000000
9DR6: 00000000; DR5&7: 00000000
10GDTR: 000000000000FFFF, IDTR: 00000000000003FF
11FLAGSINFO:c1p0a0zstido00n0rv00000000000000

Logging registers is now optional, instead of defined by debugging mode(although the no register logging mode itself blocks for compatibility with older builds, adding with the new setting).

Edit: Added space after "FLAGSINFO:" and "LDTR:".

Last edited by superfury on 2017-10-26, 20:26. Edited 1 time in total.

Author of the UniPCemu emulator.
UniPCemu Git repository
UniPCemu for Android, Windows, PSP, Vita and Switch on itch.io

Reply 49 of 90, by vladstamate

Posted on 2017-10-26, 20:25

vladstamate Offline

Rank Oldbie

Rank: Oldbie
Posts: 967
Joined: 2015-08-23, 01:43

That looks good but few notes however:

1) can we get rid of , and ; characters ? You used them inconsistently but they do not need to be printed. A space like you have is enough
2) Why is LDTR on a separate line from GDTR and IDTR? We should have all 3 in the same line In fact I think TR should be on the same line too
3) Flags is the wrong way around. least significant bit should be to the right, not left.
4) You print a CR3 where it should be a DR3

YouTube channel: https://www.youtube.com/channel/UC7HbC_nq8t1S9l7qGYL0mTA
Collection: http://www.digiloguemuseum.com/index.html
Emulator: https://sites.google.com/site/capex86/
Raytracer: https://sites.google.com/site/opaqueraytracer/

Reply 50 of 90, by superfury

Posted on 2017-10-26, 20:31

superfury Offline

Rank l33t++

Rank: l33t++
Posts: 5455
Joined: 2014-03-08, 11:25
Location: Netherlands

1,3&4: You're right, I'll fix those right away.
2: The difference is in the register type: TR and LDTR are essentially segment registers, just like the CS/DS/ES/FS/GS? IDTR/GDTR on the other hand are just simple pointers with limits, nothing more, unlike the others.

Author of the UniPCemu emulator.
UniPCemu Git repository
UniPCemu for Android, Windows, PSP, Vita and Switch on itch.io

Reply 51 of 90, by vladstamate

Posted on 2017-10-26, 20:33

vladstamate Offline

Rank Oldbie

Rank: Oldbie
Posts: 967
Joined: 2015-08-23, 01:43

superfury wrote:
2: The difference is in the register type: TR and LDTR are essentially segment registers, just like the CS/DS/ES/FS/GS? IDTR/GDTR on the other hand are just simple pointers with limits, nothing more, unlike the others.

Yes, that makes sense actually.

YouTube channel: https://www.youtube.com/channel/UC7HbC_nq8t1S9l7qGYL0mTA
Collection: http://www.digiloguemuseum.com/index.html
Emulator: https://sites.google.com/site/capex86/
Raytracer: https://sites.google.com/site/opaqueraytracer/

Reply 52 of 90, by superfury

Posted on 2017-10-26, 20:46

superfury Offline

Rank l33t++

Rank: l33t++
Posts: 5455
Joined: 2014-03-08, 11:25
Location: Netherlands

Just implemented all of those 4 points. All that's left is reversing the flags.

Edit: One strange thing though: representing the IOPL value in the flags. Reversing those would make you read them backwards instead(as a binary value)?

Edit: Reversing complete:

1F000:0000FFF0 EA 45 00 00 F0 jmp f000:00000045
2Registers:
3EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000308
4ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
5CS: F000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
6EIP: 0000fff0 EFLAGS: 00000002
7CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
8DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
9DR6: 00000000 DR5&7: 00000000
10GDTR: 000000000000FFFF IDTR: 00000000000003FF
11FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c

Edit: Fixed some inconsistencies with the logging, like uncapitalized register values:

1F000:0000FFF0 EA 45 00 00 F0 jmp f000:00000045
2Registers:
3EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000308
4ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
5CS: F000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
6EIP: 0000FFF0 EFLAGS: 00000002
7CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
8DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
9DR6: 00000000 DR5&7: 00000000
10GDTR: 000000000000FFFF IDTR: 00000000000003FF
11FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c

Do notice that the carry flag in FLAGSINFO is followed by either a space(nothing special to note), R(eset of the CPU's first instruction) or *(CPU put in a permanently hanging state deliberately due to any possible cause).

Author of the UniPCemu emulator.
UniPCemu Git repository
UniPCemu for Android, Windows, PSP, Vita and Switch on itch.io

Reply 53 of 90, by superfury

Posted on 2017-10-26, 21:34

superfury Offline

Rank l33t++

Rank: l33t++
Posts: 5455
Joined: 2014-03-08, 11:25
Location: Netherlands

If that's correct for register state(it contains all register states now after all, depending on the CPU), we still have the issue of the memory accesses. Currently, all memory accesses are dumped during the cycle they occur(one liner or multiple lines, depending on the debugging mode). It either dumps a row to the debugger log file directly(single line for memory entry) or combines them into a single line format, seperated by ;-signs:

1OPTINLINE char stringsafeDebugger(byte x)
2{
3	return (x && (x!=0xD) && (x!=0xA))?x:(char)0x20;
4}
5
6char debugger_memoryaccess_text[1024]; //Memory access text!
7char debugger_memoryaccess_line[256];
8
9void debugger_logmemoryaccess(byte iswrite, uint_32 address, byte value, byte type)
10{
11	if ((DEBUGGER_LOG==DEBUGGERLOG_ALWAYS_COMMONLOGFORMAT) || (DEBUGGER_LOG==DEBUGGERLOG_ALWAYS_DURINGSKIPSTEP_COMMONLOGFORMAT) || (DEBUGGER_LOG==DEBUGGERLOG_DEBUGGING_COMMONLOGFORMAT)) //Common log format?
12	{
13		return; //No memory access logging, we're disabled for now!
14	}
15	if (iswrite)
16	{
17		switch (type)
18		{
19			case LOGMEMORYACCESS_NORMAL:
20				if ((DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE_SIMPLIFIED) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE_SIMPLIFIED)) //Not using a single line?
21				{
22					log_timestampbackup = log_logtimestamp(2); //Save state!
23					log_logtimestamp(debugger_loggingtimestamp); //Are we to log the timestamp?
24					dolog("debugger","Writing to normal memory: %08X=%02X (%c)",address,value,stringsafeDebugger(value));
25					log_logtimestamp(log_timestampbackup); //Restore state!
26				}
27				else
28				{
29					if (strcmp(debugger_memoryaccess_text,"")==0) //Nothing logged yet?
30					{
31						sprintf(debugger_memoryaccess_text,"Normal(w):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
32					}
33					else
34					{
35						sprintf(debugger_memoryaccess_line,"Normal(w):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
36						strcat(debugger_memoryaccess_text,"; ");
37						strcat(debugger_memoryaccess_text,debugger_memoryaccess_line); //Add the line!
38					}
39				}
40				break;
41			case LOGMEMORYACCESS_PAGED:
42				if ((DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE_SIMPLIFIED) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE_SIMPLIFIED)) //Not using a single line?
43				{
44					log_timestampbackup = log_logtimestamp(2); //Save state!
45					log_logtimestamp(debugger_loggingtimestamp); //Are we to log the timestamp?
46					dolog("debugger","Writing to paged memory: %08X=%02X (%c)",address,value,stringsafeDebugger(value));
47					log_logtimestamp(log_timestampbackup); //Restore state!
48				}
49				else
50				{
51					if (strcmp(debugger_memoryaccess_text,"")==0) //Nothing logged yet?
52					{
53						sprintf(debugger_memoryaccess_text,"Paged(w):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
54					}
55					else
56					{
57						sprintf(debugger_memoryaccess_line,"Paged(w):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
58						strcat(debugger_memoryaccess_text,"; ");
59						strcat(debugger_memoryaccess_text,debugger_memoryaccess_line); //Add the line!
60					}

…Show last 189 lines

61				}
62				break;
63			case LOGMEMORYACCESS_DIRECT:
64				if ((DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE_SIMPLIFIED) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE_SIMPLIFIED)) //Not using a single line?
65				{
66					log_timestampbackup = log_logtimestamp(2); //Save state!
67					log_logtimestamp(debugger_loggingtimestamp); //Are we to log the timestamp?
68					dolog("debugger","Writing to physical memory: %08X=%02X (%c)",address,value,stringsafeDebugger(value));
69					log_logtimestamp(log_timestampbackup); //Restore state!
70				}
71				else
72				{
73					if (strcmp(debugger_memoryaccess_text,"")==0) //Nothing logged yet?
74					{
75						sprintf(debugger_memoryaccess_text,"Physical(w):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
76					}
77					else
78					{
79						sprintf(debugger_memoryaccess_line,"Physical(w):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
80						strcat(debugger_memoryaccess_text,"; ");
81						strcat(debugger_memoryaccess_text,debugger_memoryaccess_line); //Add the line!
82					}
83				}
84				break;
85			default:
86			case LOGMEMORYACCESS_RAM:
87				if ((DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE_SIMPLIFIED) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE_SIMPLIFIED)) //Not using a single line?
88				{
89					log_timestampbackup = log_logtimestamp(2); //Save state!
90					log_logtimestamp(debugger_loggingtimestamp); //Are we to log the timestamp?
91					dolog("debugger","Writing to RAM: %08X=%02X (%c)",address,value,stringsafeDebugger(value));
92					log_logtimestamp(log_timestampbackup); //Restore state!
93				}
94				else
95				{
96					if (strcmp(debugger_memoryaccess_text,"")==0) //Nothing logged yet?
97					{
98						sprintf(debugger_memoryaccess_text,"RAM(w):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
99					}
100					else
101					{
102						sprintf(debugger_memoryaccess_line,"RAM(w):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
103						strcat(debugger_memoryaccess_text,"; ");
104						strcat(debugger_memoryaccess_text,debugger_memoryaccess_line); //Add the line!
105					}
106				}
107				break;
108			case LOGMEMORYACCESS_RAM_LOGMMUALL:
109				if ((DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE_SIMPLIFIED) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE_SIMPLIFIED)) //Not using a single line?
110				{
111					log_timestampbackup = log_logtimestamp(2); //Save state!
112					log_logtimestamp(debugger_loggingtimestamp); //Are we to log the timestamp?
113					dolog("debugger","MMU: Writing to real %08X=%02X (%c)",address,value,stringsafeDebugger(value));
114					log_logtimestamp(log_timestampbackup); //Restore state!
115				}
116				else
117				{
118					if (strcmp(debugger_memoryaccess_text,"")==0) //Nothing logged yet?
119					{
120						sprintf(debugger_memoryaccess_text,"RealRAM(w):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
121					}
122					else
123					{
124						sprintf(debugger_memoryaccess_line,"RealRAM(w):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
125						strcat(debugger_memoryaccess_text,"; ");
126						strcat(debugger_memoryaccess_text,debugger_memoryaccess_line); //Add the line!
127					}
128				}
129				break;
130		}
131	}
132	else
133	{
134		switch (type)
135		{
136			case LOGMEMORYACCESS_NORMAL:
137				if ((DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE_SIMPLIFIED) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE_SIMPLIFIED)) //Not using a single line?
138				{
139					log_timestampbackup = log_logtimestamp(2); //Save state!
140					log_logtimestamp(debugger_loggingtimestamp); //Are we to log the timestamp?
141					dolog("debugger","Reading from normal memory: %08X=%02X (%c)",address,value,stringsafeDebugger(value));
142					log_logtimestamp(log_timestampbackup); //Restore state!
143				}
144				else
145				{
146					if (strcmp(debugger_memoryaccess_text,"")==0) //Nothing logged yet?
147					{
148						sprintf(debugger_memoryaccess_text,"Normal(r):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
149					}
150					else
151					{
152						sprintf(debugger_memoryaccess_line,"Normal(r):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
153						strcat(debugger_memoryaccess_text,"; ");
154						strcat(debugger_memoryaccess_text,debugger_memoryaccess_line); //Add the line!
155					}
156				}
157				break;
158			case LOGMEMORYACCESS_PAGED:
159				if ((DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE_SIMPLIFIED) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE_SIMPLIFIED)) //Not using a single line?
160				{
161					log_timestampbackup = log_logtimestamp(2); //Save state!
162					log_logtimestamp(debugger_loggingtimestamp); //Are we to log the timestamp?
163					dolog("debugger","Reading from paged memory: %08X=%02X (%c)",address,value,stringsafeDebugger(value));
164					log_logtimestamp(log_timestampbackup); //Restore state!
165				}
166				else
167				{
168					if (strcmp(debugger_memoryaccess_text,"")==0) //Nothing logged yet?
169					{
170						sprintf(debugger_memoryaccess_text,"Paged(r):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
171					}
172					else
173					{
174						sprintf(debugger_memoryaccess_line,"Paged(r):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
175						strcat(debugger_memoryaccess_text,"; ");
176						strcat(debugger_memoryaccess_text,debugger_memoryaccess_line); //Add the line!
177					}
178				}
179				break;
180			case LOGMEMORYACCESS_DIRECT:
181				if ((DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE_SIMPLIFIED) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE_SIMPLIFIED)) //Not using a single line?
182				{
183					log_timestampbackup = log_logtimestamp(2); //Save state!
184					log_logtimestamp(debugger_loggingtimestamp); //Are we to log the timestamp?
185					dolog("debugger","Reading from physical memory: %08X=%02X (%c)",address,value,stringsafeDebugger(value));
186					log_logtimestamp(log_timestampbackup); //Restore state!
187				}
188				else
189				{
190					if (strcmp(debugger_memoryaccess_text,"")==0) //Nothing logged yet?
191					{
192						sprintf(debugger_memoryaccess_text,"Physical(r):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
193					}
194					else
195					{
196						sprintf(debugger_memoryaccess_line,"Physical(r):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
197						strcat(debugger_memoryaccess_text,"; ");
198						strcat(debugger_memoryaccess_text,debugger_memoryaccess_line); //Add the line!
199					}
200				}
201				break;
202			default:
203			case LOGMEMORYACCESS_RAM:
204				if ((DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE_SIMPLIFIED) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE_SIMPLIFIED)) //Not using a single line?
205				{
206					log_timestampbackup = log_logtimestamp(2); //Save state!
207					log_logtimestamp(debugger_loggingtimestamp); //Are we to log the timestamp?
208					dolog("debugger","Reading from RAM: %08X=%02X (%c)",address,value,stringsafeDebugger(value));
209					log_logtimestamp(log_timestampbackup); //Restore state!
210				}
211				else
212				{
213					if (strcmp(debugger_memoryaccess_text,"")==0) //Nothing logged yet?
214					{
215						sprintf(debugger_memoryaccess_text,"RAM(r):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
216					}
217					else
218					{
219						sprintf(debugger_memoryaccess_line,"RAM(r):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
220						strcat(debugger_memoryaccess_text,"; ");
221						strcat(debugger_memoryaccess_text,debugger_memoryaccess_line); //Add the line!
222					}
223				}
224				break;
225			case LOGMEMORYACCESS_RAM_LOGMMUALL:
226				if ((DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE) && (DEBUGGER_LOG!=DEBUGGERLOG_ALWAYS_SINGLELINE_SIMPLIFIED) && (DEBUGGER_LOG!=DEBUGGERLOG_DEBUGGING_SINGLELINE_SIMPLIFIED)) //Not using a single line?
227				{
228					log_timestampbackup = log_logtimestamp(2); //Save state!
229					log_logtimestamp(debugger_loggingtimestamp); //Are we to log the timestamp?
230					dolog("debugger","MMU: Reading from real %08X=%02X (%c)",address,value,stringsafeDebugger(value));
231					log_logtimestamp(log_timestampbackup); //Restore state!
232				}
233				else
234				{
235					if (strcmp(debugger_memoryaccess_text,"")==0) //Nothing logged yet?
236					{
237						sprintf(debugger_memoryaccess_text,"RealRAM(r):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
238					}
239					else
240					{
241						sprintf(debugger_memoryaccess_line,"RealRAM(r):%08X=%02X(%c)",address,value,stringsafeDebugger(value)); //Compact version!
242						strcat(debugger_memoryaccess_text,"; ");
243						strcat(debugger_memoryaccess_text,debugger_memoryaccess_line); //Add the line!
244					}
245				}
246				break;
247		}
248	}
249}

Btw the Reset flag(R at the end of the flags) is only shown when the CPU has been reset at the end of the previous running instruction. Starting to go fetching an instruction(first CPU state, which happens when the first instruction is starting to fetch, after the CPU completes an instruction(BIU becomes ready again etc. causing a reset caused by software, never happens when emulation is started(as no reset is triggered by the CPU, it's cleared when the first instruction starts fetching after all)). So it only happens when it's reset after the debugger parses an instruction and the next instruction starts fetching after the CPU is reset.

Author of the UniPCemu emulator.
UniPCemu Git repository
UniPCemu for Android, Windows, PSP, Vita and Switch on itch.io

Reply 54 of 90, by superfury

Posted on 2017-10-27, 00:16

superfury Offline

Rank l33t++

Rank: l33t++
Posts: 5455
Joined: 2014-03-08, 11:25
Location: Netherlands

Also, now that I see it, does the register contents need to be upper case or lower case hex?(%08X/%04X vs %08x/%04x)

Author of the UniPCemu emulator.
UniPCemu Git repository
UniPCemu for Android, Windows, PSP, Vita and Switch on itch.io

Reply 55 of 90, by vladstamate

Posted on 2017-10-27, 12:30

vladstamate Offline

Rank Oldbie

Rank: Oldbie
Posts: 967
Joined: 2015-08-23, 01:43

Probably lowercase, as that is what we've done with the other addresses.

YouTube channel: https://www.youtube.com/channel/UC7HbC_nq8t1S9l7qGYL0mTA
Collection: http://www.digiloguemuseum.com/index.html
Emulator: https://sites.google.com/site/capex86/
Raytracer: https://sites.google.com/site/opaqueraytracer/

Reply 56 of 90, by superfury

Posted on 2017-10-27, 13:02

superfury Offline

Rank l33t++

Rank: l33t++
Posts: 5455
Joined: 2014-03-08, 11:25
Location: Netherlands

OK. Now the entire universal log format is in lower case(except register names, which are in upper case). The only thing still left in upper case is the instruction opcode bytes themselves(e.g. 5b for an POP BX instruction, which follows the instruction address itself).

Now, what do we do about memory accesses(e.g. data read/written to/from memory by instructions e.g. MOV word DS:[SI], BX)? How do we log those in the common log format? Also, how do we handle stuff like the different levels of address spaces translation layers(logical -> linear -> physical -> hardware/RAM) in the common log format? The format I'm using is relatively pretty simple: just the kind of access(read or write) combined with the address translation for each layer(which may start from any point, depending on the access that's being made) and values that are transferred between the layers(the byte read/written to the storage backend(RAM or hardware like VGA)). The BIU always starts at the physical layer(it gets fed a physical address to process after all), except for the PIQ fetches themselves(which start at the logical level(CS:(E)IP)).

Any ideas?

Example log that's currently generating for the common log format with registers for the 80386 CPU running the test386.asm BIOS:

1f000:0000fff0 EA 45 00 00 F0 jmp f000:00000045
2Registers:
3EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000308
4ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
5CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
6EIP: 0000fff0 EFLAGS: 00000002
7CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
8DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
9DR6: 00000000 DR5&7: 00000000
10GDTR: 000000000000ffff IDTR: 00000000000003ff
11FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c 
12f000:00000045 FA cli
13Registers:
14EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000308
15ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
16CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
17EIP: 00000045 EFLAGS: 00000002
18CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
19DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
20DR6: 00000000 DR5&7: 00000000
21GDTR: 000000000000ffff IDTR: 00000000000003ff
22FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c 
23f000:00000046 B0 00 mov al,00
24Registers:
25EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000308
26ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
27CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
28EIP: 00000046 EFLAGS: 00000002
29CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
30DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
31DR6: 00000000 DR5&7: 00000000
32GDTR: 000000000000ffff IDTR: 00000000000003ff
33FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c 
34f000:00000048 BA 84 00 mov dx,0084
35Registers:
36EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000308
37ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
38CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
39EIP: 00000048 EFLAGS: 00000002
40CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
41DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
42DR6: 00000000 DR5&7: 00000000
43GDTR: 000000000000ffff IDTR: 00000000000003ff
44FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c 
45f000:0000004b EE out dx,al
46Registers:
47EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000084
48ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
49CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
50EIP: 0000004b EFLAGS: 00000002
51CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
52DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
53DR6: 00000000 DR5&7: 00000000
54GDTR: 000000000000ffff IDTR: 00000000000003ff
55FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c 
56f000:0000004c B4 01 mov ah,01
57Registers:
58EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000084
59ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
60CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000

…Show last 61 lines

61EIP: 0000004c EFLAGS: 00000002
62CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
63DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
64DR6: 00000000 DR5&7: 00000000
65GDTR: 000000000000ffff IDTR: 00000000000003ff
66FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c 
67f000:0000004e 9E sahf
68Registers:
69EAX: 00000100 EBX: 00000000 ECX: 00000000 EDX: 00000084
70ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
71CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
72EIP: 0000004e EFLAGS: 00000002
73CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
74DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
75DR6: 00000000 DR5&7: 00000000
76GDTR: 000000000000ffff IDTR: 00000000000003ff
77FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c 
78f000:0000004f 73 24 jae 00000075
79Registers:
80EAX: 00000100 EBX: 00000000 ECX: 00000000 EDX: 00000084
81ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
82CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
83EIP: 0000004f EFLAGS: 00000003
84CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
85DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
86DR6: 00000000 DR5&7: 00000000
87GDTR: 000000000000ffff IDTR: 00000000000003ff
88FLAGSINFO: 00000000000000vr0n00oditsz0a0p1C 
89f000:00000051 72 23 jb 00000076
90Registers:
91EAX: 00000100 EBX: 00000000 ECX: 00000000 EDX: 00000084
92ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
93CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
94EIP: 00000051 EFLAGS: 00000003
95CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
96DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
97DR6: 00000000 DR5&7: 00000000
98GDTR: 000000000000ffff IDTR: 00000000000003ff
99FLAGSINFO: 00000000000000vr0n00oditsz0a0p1C 
100f000:00000076 72 DC jb 00000054
101Registers:
102EAX: 00000100 EBX: 00000000 ECX: 00000000 EDX: 00000084
103ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
104CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
105EIP: 00000076 EFLAGS: 00000003
106CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
107DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
108DR6: 00000000 DR5&7: 00000000
109GDTR: 000000000000ffff IDTR: 00000000000003ff
110FLAGSINFO: 00000000000000vr0n00oditsz0a0p1C 
111f000:00000054 B4 40 mov ah,40
112Registers:
113EAX: 00000100 EBX: 00000000 ECX: 00000000 EDX: 00000084
114ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
115CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
116EIP: 00000054 EFLAGS: 00000003
117CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
118DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
119DR6: 00000000 DR5&7: 00000000
120GDTR: 000000000000ffff IDTR: 00000000000003ff
121FLAGSINFO: 00000000000000vr0n00oditsz0a0p1C

Edit: Btw(a bit offtopic), I just noticed a new SDL2 2.0.7 having been released. I sure hope that fixes the problem with SDL2.dll crashing within it's own thread when disconnecting from Windows 10 Remote Desktop(it started crashing with 2.0.6 for unknown reasons, nothing to do with my emulator).
Edit: Unfortunately, it still crashes:

1Exception thrown at 0x000000006C82634B (SDL2.dll) in UniPCemu_x64.exe:
20xC0000005: Access violation reading location 0x0000000000000000)

Author of the UniPCemu emulator.
UniPCemu Git repository
UniPCemu for Android, Windows, PSP, Vita and Switch on itch.io

Reply 57 of 90, by vladstamate

Posted on 2017-10-27, 15:16

vladstamate Offline

Rank Oldbie

Rank: Oldbie
Posts: 967
Joined: 2015-08-23, 01:43

Show us an example of what you have given an instruction that writes out something, or reads something.

YouTube channel: https://www.youtube.com/channel/UC7HbC_nq8t1S9l7qGYL0mTA
Collection: http://www.digiloguemuseum.com/index.html
Emulator: https://sites.google.com/site/capex86/
Raytracer: https://sites.google.com/site/opaqueraytracer/

Reply 58 of 90, by superfury

Posted on 2017-10-27, 16:00

superfury Offline

Rank l33t++

Rank: l33t++
Posts: 5455
Joined: 2014-03-08, 11:25
Location: Netherlands

OK. I've made a little log of the first BIOS ROM executions with the full memory log enabled(seperate line for each layer, used with the normal debugging log modes in UniPCemu):

1Reading from physical memory: FFFFFFF0=EA (ê)
2Reading from paged memory: FFFFFFF0=EA (ê)
3Reading from physical memory: FFFFFFF1=45 (E)
4Reading from paged memory: FFFFFFF1=45 (E)
5Reading from physical memory: FFFFFFF2=00 ( )
6Reading from paged memory: FFFFFFF2=00 ( )
7Reading from physical memory: FFFFFFF3=00 ( )
8Reading from paged memory: FFFFFFF3=00 ( )
9Reading from physical memory: FFFFFFF4=F0 (ð)
10Reading from paged memory: FFFFFFF4=F0 (ð)
11Reading from physical memory: FFFFFFF5=32 (2)
12Reading from paged memory: FFFFFFF5=32 (2)
13Reading from physical memory: FFFFFFF6=31 (1)
14Reading from paged memory: FFFFFFF6=31 (1)
15Reading from physical memory: FFFFFFF7=2F (/)
16Reading from paged memory: FFFFFFF7=2F (/)
17f000:0000fff0 EA 45 00 00 F0 jmp f000:00000045
18Registers:
19EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000308
20ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
21CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
22EIP: 0000fff0 EFLAGS: 00000002
23CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
24DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
25DR6: 00000000 DR5&7: 00000000
26GDTR: 000000000000ffff IDTR: 00000000000003ff
27FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c 
28Reading from physical memory: 000F0045=FA (ú)
29Reading from paged memory: 000F0045=FA (ú)
30Reading from physical memory: 000F0046=B0 (°)
31Reading from paged memory: 000F0046=B0 (°)
32Reading from physical memory: 000F0047=00 ( )
33Reading from paged memory: 000F0047=00 ( )
34Reading from physical memory: 000F0048=BA (º)
35Reading from paged memory: 000F0048=BA (º)
36Reading from physical memory: 000F0049=84 („)
37Reading from paged memory: 000F0049=84 („)
38Reading from physical memory: 000F004A=00 ( )
39Reading from paged memory: 000F004A=00 ( )
40Reading from physical memory: 000F004B=EE (î)
41Reading from paged memory: 000F004B=EE (î)
42Reading from physical memory: 000F004C=B4 (´)
43Reading from paged memory: 000F004C=B4 (´)
44Reading from physical memory: 000F004D=01 ()
45Reading from paged memory: 000F004D=01 ()
46Reading from physical memory: 000F004E=9E (ž)
47Reading from paged memory: 000F004E=9E (ž)
48Reading from physical memory: 000F004F=73 (s)
49Reading from paged memory: 000F004F=73 (s)
50Reading from physical memory: 000F0050=24 ($)
51Reading from paged memory: 000F0050=24 ($)
52Reading from physical memory: 000F0051=72 (r)
53Reading from paged memory: 000F0051=72 (r)
54Reading from physical memory: 000F0052=23 (#)
55Reading from paged memory: 000F0052=23 (#)
56Reading from physical memory: 000F0053=F4 (ô)
57Reading from paged memory: 000F0053=F4 (ô)
58Reading from physical memory: 000F0054=B4 (´)
59Reading from paged memory: 000F0054=B4 (´)
60f000:00000045 FA cli

…Show last 81 lines

61Registers:
62EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000308
63ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
64CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
65EIP: 00000045 EFLAGS: 00000002
66CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
67DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
68DR6: 00000000 DR5&7: 00000000
69GDTR: 000000000000ffff IDTR: 00000000000003ff
70FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c 
71f000:00000046 B0 00 mov al,00
72Registers:
73EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000308
74ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
75CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
76EIP: 00000046 EFLAGS: 00000002
77CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
78DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
79DR6: 00000000 DR5&7: 00000000
80GDTR: 000000000000ffff IDTR: 00000000000003ff
81FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c 
82Reading from physical memory: 000F0055=40 (@)
83Reading from paged memory: 000F0055=40 (@)
84Reading from physical memory: 000F0056=9E (ž)
85Reading from paged memory: 000F0056=9E (ž)
86Reading from physical memory: 000F0057=75 (u)
87Reading from paged memory: 000F0057=75 (u)
88Reading from physical memory: 000F0058=1C ()
89Reading from paged memory: 000F0058=1C ()
90f000:00000048 BA 84 00 mov dx,0084
91Registers:
92EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000308
93ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
94CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
95EIP: 00000048 EFLAGS: 00000002
96CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
97DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
98DR6: 00000000 DR5&7: 00000000
99GDTR: 000000000000ffff IDTR: 00000000000003ff
100FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c 
101f000:0000004b EE out dx,al
102Registers:
103EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000084
104ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
105CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
106EIP: 0000004b EFLAGS: 00000002
107CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
108DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
109DR6: 00000000 DR5&7: 00000000
110GDTR: 000000000000ffff IDTR: 00000000000003ff
111FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c 
112Reading from physical memory: 000F0059=74 (t)
113Reading from paged memory: 000F0059=74 (t)
114Reading from physical memory: 000F005A=1D ()
115Reading from paged memory: 000F005A=1D ()
116Reading from physical memory: 000F005B=F4 (ô)
117Reading from paged memory: 000F005B=F4 (ô)
118Reading from physical memory: 000F005C=B4 (´)
119Reading from paged memory: 000F005C=B4 (´)
120f000:0000004c B4 01 mov ah,01
121Registers:
122EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000084
123ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
124CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
125EIP: 0000004c EFLAGS: 00000002
126CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
127DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
128DR6: 00000000 DR5&7: 00000000
129GDTR: 000000000000ffff IDTR: 00000000000003ff
130FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c 
131f000:0000004e 9E sahf
132Registers:
133EAX: 00000100 EBX: 00000000 ECX: 00000000 EDX: 00000084
134ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
135CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
136EIP: 0000004e EFLAGS: 00000002
137CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
138DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
139DR6: 00000000 DR5&7: 00000000
140GDTR: 000000000000ffff IDTR: 00000000000003ff
141FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c

Also, one with the single line format logging method instead(used with the cycle logging mode of UniPCemu, a tab at the start being the remnant of the seperation process for easy parsability(usually the first column is the executed cycle, which doesn't appear here), while easy to parse due to identifying tabs at the start(think Makefile rules of an instruction executing, although it's just remnants of UniPCemu's state logging method). It's essentially lines of one byte/word/dword being read and the path each byte takes):

1		Physical(r):FFFFFFF0=EA(ê); Paged(r):FFFFFFF0=EA(ê); Physical(r):FFFFFFF1=45(E); Paged(r):FFFFFFF1=45(E); Physical(r):FFFFFFF2=00( ); Paged(r):FFFFFFF2=00( ); Physical(r):FFFFFFF3=00( ); Paged(r):FFFFFFF3=00( )
2		Physical(r):FFFFFFF4=F0(ð); Paged(r):FFFFFFF4=F0(ð); Physical(r):FFFFFFF5=32(2); Paged(r):FFFFFFF5=32(2); Physical(r):FFFFFFF6=31(1); Paged(r):FFFFFFF6=31(1); Physical(r):FFFFFFF7=2F(/); Paged(r):FFFFFFF7=2F(/)
3f000:0000fff0 EA 45 00 00 F0 jmp f000:00000045
4Registers:
5EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000308
6ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
7CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
8EIP: 0000fff0 EFLAGS: 00000002
9CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
10DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
11DR6: 00000000 DR5&7: 00000000
12GDTR: 000000000000ffff IDTR: 00000000000003ff
13FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c 
14		Physical(r):000F0045=FA(ú); Paged(r):000F0045=FA(ú); Physical(r):000F0046=B0(°); Paged(r):000F0046=B0(°); Physical(r):000F0047=00( ); Paged(r):000F0047=00( ); Physical(r):000F0048=BA(º); Paged(r):000F0048=BA(º)
15		Physical(r):000F0049=84(„); Paged(r):000F0049=84(„); Physical(r):000F004A=00( ); Paged(r):000F004A=00( ); Physical(r):000F004B=EE(î); Paged(r):000F004B=EE(î); Physical(r):000F004C=B4(´); Paged(r):000F004C=B4(´)
16		Physical(r):000F004D=01(); Paged(r):000F004D=01(); Physical(r):000F004E=9E(ž); Paged(r):000F004E=9E(ž); Physical(r):000F004F=73(s); Paged(r):000F004F=73(s); Physical(r):000F0050=24($); Paged(r):000F0050=24($)
17		Physical(r):000F0051=72(r); Paged(r):000F0051=72(r); Physical(r):000F0052=23(#); Paged(r):000F0052=23(#); Physical(r):000F0053=F4(ô); Paged(r):000F0053=F4(ô); Physical(r):000F0054=B4(´); Paged(r):000F0054=B4(´)
18f000:00000045 FA cli
19Registers:
20EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000308
21ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
22CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
23EIP: 00000045 EFLAGS: 00000002
24CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
25DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
26DR6: 00000000 DR5&7: 00000000
27GDTR: 000000000000ffff IDTR: 00000000000003ff
28FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c 
29f000:00000046 B0 00 mov al,00
30Registers:
31EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000308
32ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
33CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
34EIP: 00000046 EFLAGS: 00000002
35CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
36DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
37DR6: 00000000 DR5&7: 00000000
38GDTR: 000000000000ffff IDTR: 00000000000003ff
39FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c 
40f000:00000048 BA 84 00 mov dx,0084	Physical(r):000F0055=40(@); Paged(r):000F0055=40(@); Physical(r):000F0056=9E(ž); Paged(r):000F0056=9E(ž); Physical(r):000F0057=75(u); Paged(r):000F0057=75(u); Physical(r):000F0058=1C(); Paged(r):000F0058=1C()
41Registers:
42EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000308
43ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
44CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
45EIP: 00000048 EFLAGS: 00000002
46CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
47DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
48DR6: 00000000 DR5&7: 00000000
49GDTR: 000000000000ffff IDTR: 00000000000003ff
50FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c 
51f000:0000004b EE out dx,al
52Registers:
53EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000084
54ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
55CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
56EIP: 0000004b EFLAGS: 00000002
57CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
58DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
59DR6: 00000000 DR5&7: 00000000
60GDTR: 000000000000ffff IDTR: 00000000000003ff

…Show last 23 lines

61FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c 
62f000:0000004c B4 01 mov ah,01	Physical(r):000F0059=74(t); Paged(r):000F0059=74(t); Physical(r):000F005A=1D(); Paged(r):000F005A=1D(); Physical(r):000F005B=F4(ô); Paged(r):000F005B=F4(ô); Physical(r):000F005C=B4(´); Paged(r):000F005C=B4(´)
63Registers:
64EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000084
65ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
66CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
67EIP: 0000004c EFLAGS: 00000002
68CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
69DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
70DR6: 00000000 DR5&7: 00000000
71GDTR: 000000000000ffff IDTR: 00000000000003ff
72FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c 
73f000:0000004e 9E sahf
74Registers:
75EAX: 00000100 EBX: 00000000 ECX: 00000000 EDX: 00000084
76ESP: 00000000 EBP: 00000000 ESI: 00000000 EDI: 00000000
77CS: f000 DS: 0000 ES: 0000 FS: 0000 GS: 0000 SS: 0000 TR: 0000 LDTR: 0000
78EIP: 0000004e EFLAGS: 00000002
79CR0: 00000000 CR1: 00000000 CR2: 00000000 CR3: 00000000
80DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
81DR6: 00000000 DR5&7: 00000000
82GDTR: 000000000000ffff IDTR: 00000000000003ff
83FLAGSINFO: 00000000000000vr0n00oditsz0a0p1c

Ideas on those formats(NULL byte as well as carriage return and backspace being patched to space character instead with text representation between parenteses)?

Author of the UniPCemu emulator.
UniPCemu Git repository
UniPCemu for Android, Windows, PSP, Vita and Switch on itch.io

Reply 59 of 90, by vladstamate

Posted on 2017-10-27, 16:21

vladstamate Offline

Rank Oldbie

Rank: Oldbie
Posts: 967
Joined: 2015-08-23, 01:43

When would those be different? In PM when paging is on?

1Reading from physical memory: 000F0059=74 (t)
2Reading from paged memory: 000F0059=74 (t)

By paged memory you mean virtual memory/address?

YouTube channel: https://www.youtube.com/channel/UC7HbC_nq8t1S9l7qGYL0mTA
Collection: http://www.digiloguemuseum.com/index.html
Emulator: https://sites.google.com/site/capex86/
Raytracer: https://sites.google.com/site/opaqueraytracer/

Main menu

Common searches

Topic actions

Reply 40 of 90, by superfury

Reply 41 of 90, by vladstamate

Reply 42 of 90, by superfury

Reply 43 of 90, by superfury

Reply 44 of 90, by vladstamate

Reply 45 of 90, by superfury

Reply 46 of 90, by vladstamate

Reply 47 of 90, by superfury

Reply 48 of 90, by superfury

Reply 49 of 90, by vladstamate

Reply 50 of 90, by superfury

Reply 51 of 90, by vladstamate

Reply 52 of 90, by superfury

Reply 53 of 90, by superfury

Reply 54 of 90, by superfury

Reply 55 of 90, by vladstamate

Reply 56 of 90, by superfury

Reply 57 of 90, by vladstamate

Reply 58 of 90, by superfury

Reply 59 of 90, by vladstamate