Files
TeslaRel410/emulator/render-bridge/logs/070-dosbox.txt
T
CydandClaude Fable 5 edb1670900 BT410 5.3.75: the quiet conf faults 3/3 -- logging SUPPRESSES the fault
Hypothesis: our BT_* logging inflates the load window, the window is the
exposure, so a quiet run should load faster and fault less.  Both halves
wrong.  pod_render_quiet -- which differs from pod_render_rec by exactly the
six BT_* logging vars -- faulted 3/3, same signature, against ~25-40% for the
logged conf.

That is the strongest evidence yet that the residual is a timing-sensitive
HOST bug rather than anything about our data: writing to COM3 changes when
interrupts land relative to the DPMI host's handler-chain walk, and nothing
about our attribute tables or renderables could plausibly be modulated by
whether we print to a serial port.  Interrupt phase can.

Two immediate consequences: pod_render_rec is the LESS fault-prone rig, so
use it; and the 'shipped survives' baseline weakens further, since shipped
also writes plenty to COM3 and so sits on the suppressed side of the same
effect on top of its shorter window.

The wall-clock numbers also correct an earlier assumption: 150-275s
boot+load, not ~60s.  The 60s figure was the load DRAIN in game ticks; DOS
boot, two diagnose passes and card init dominate the rest.

Next is clearly emulator-side: the host keeps no EBP frames (the frame walk
returned one bogus entry), so naming the routine that owns the chain needs a
breakpoint-style trace of entries to 0x66CF with the head node, diffing a
clean run against a faulting one.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-07-29 18:51:35 -05:00

225 lines
15 KiB
Plaintext

LOG: Early LOG Init complete
LOG: CONFIG: Loaded config file: C:/VWE/TeslaRel410/emulator/render-bridge/pod_render_quiet.conf
LOG: DOSBox-X's working directory: C:\VWE\TeslaRel410\emulator\src\src
LOG: Logging init: beginning logging proper. This is the end of the early init logging
LOG: Logging: No logfile was given. All further logging will be discarded.
LOG: DOSBox-X version 2026.06.02 Commit d75a57c (MinGW SDL2 64-bit)
LOG: Prevent capture: 0
LOG: SDL: version 2.32.10, Video windows, Audio directsound
LOG: EXPERIMENTAL: Debugger enabled for MinGW build, DOSBox-X crashes depending on the terminal software you use. Launching from command prompt (cmd.exe) is recommended.
LOG: Windows keyboard layout ID is 0x0409
LOG: Host keyboard layout is now us (US English)
LOG: Mapper keyboard layout is now us (US English)
LOG: SDL2 reports desktop display mode 3440 x 1440
LOG: OpenGL Version : 4.6.0 NVIDIA 610.47
LOG: Configured windowposition: -
LOG: SDL: Current window pixel format: SDL_PIXELFORMAT_RGB888
LOG: SDL: You are running in 24 bpp mode, this will slow down things!
LOG: Releasing keyboard
LOG: SDL: Windows 11 round corners will be disabled.
LOG: Screen report: Method 'Win98base' (3440.000 x 1440.000 pixels) at (0.000 x 0.000) (910.167 x 381.000 mm) (35.833 x 15.000 in) (96.000 x 96.000 DPI)
LOG: ISA BCLK: 8333333.333Hz (25000000/3)
LOG: monopal: green,
LOG: Active save slot: 1 [Empty]
LOG: USING AVI+ZMBV
LOG: Pentium CMPXCHG8B emulation is enabled
LOG: Max 1073741824 sz 32768
LOG: Final 32768
LOG: Final arrangement: Below 4GB = 32768KB, Above 4GB = 0KB
LOG: VPXLOG: fifosock listening on 127.0.0.1:8621
LOG: VPXLOG: live render backend started
LOG: VPXLOG: base 0x150 respond=1 handshakes=3 log='C:\Users\cyd\AppData\Local/Temp/vwe-pod/vpxresp.txt'
LOG: MIDI:Opened device:win32
LOG: mic_input: Selected microphone device: Microphone (Steam Streaming Microphone)
LOG: One joystick reported, initializing with 4axis
LOG: Using joystick Xbox One Controller with 6 axes, 16 buttons and 1 hat(s)
LOG: VOODOO LFB now at d0000000
LOG: Serial1: BASE 3f8h
LOG: Serial1: namedpipe client of \\.\pipe\vrio (poll 0.10ms burst x16)
LOG: Serial1: namedpipe connected to \\.\pipe\vrio
LOG: Serial2: BASE 2f8h
LOG: Serial2: namedpipe client of \\.\pipe\vplasma (poll 1.00ms burst x1)
LOG: Serial2: namedpipe connected to \\.\pipe\vplasma
LOG: Serial3: BASE 3e8h
LOG: Serial: port 3 will write to file C:\VWE\TeslaRel410\emulator\render-bridge\podlog.txt
LOG: Parallel1: BASE 378h
LOG: MPU-401 Registering I/O ports as if IBM PC MPU-401 at base 330h
LOG: Memory I/O complexity optimization enabled aka option 'memory io optimization 1'. If the game or demo is unable to draw to the screen properly, set the option to false.
LOG: The 'scanline render on demand' option is available and may provide a modest boost in video render performance if set to true.
LOG: Allocated APM BIOS pm entry point at f000:ce40
LOG: Writing code to fce40
LOG: Writing code to fce60
LOG: Windows: IID_ITaskbarList3 is available
LOG: ISA Plug & Play BIOS enabled
LOG: VGA ROM BIOS init callback
LOG: pixratio 1.000, dw false, dh false
LOG: Aspect ratio: 640 x 480 xToY=1.333 yToX=0.750
LOG: WARNING: No translation support (to host) for code page 0
LOG: DOS keyboard layout loaded with main language code US for layout us
LOG: XMS: 50 handles allocated for use by the DOS environment
LOG: EMS page frame at 0xe000-0xefff
LOG: COMMAND.COM env size: 720 bytes
LOG: COMMAND.COM environment block: 0x0701 sz=0x002d
LOG: COMMAND.COM main body (PSP): 0x072f sz=0x009a
LOG: COMMAND.COM stack: 0x0749
LOG: pixratio 1.350, dw false, dh false
LOG: Aspect ratio: 720 x 540 xToY=1.333 yToX=0.750
LOG: SHELL:Redirect output to COM3
LOG: VPXLOG: fifosock client connected
VPX lights@f1: type6=0 typeE=0 decoded=0 dir=0 amb(0.00,0.00,0.00)
LOG: 185087598 ERROR MOUSE:Unhandled videomode 79 on reset
LOG: pixratio 1.000, dw false, dh false
LOG: Aspect ratio: 640 x 480 xToY=1.333 yToX=0.750
VPX lightnode t=6 nb=52: [8]00000000/0 [12]00000000/0 [16]00000001/1.4013e-45 [20]3f800000/1 [24]3f800000/1 [28]3f800000/1 [32]64078678/1e+22 [36]64078678/1e+22 [40]00000000/0 [44]bf6ae9ee/-0.917632 [48]ffffffff/nan
LOG: Serial1: Errors: Framing 0, Parity 0, Overrun RX:1 (IF0:1), TX:0, Break 0
LOG: Serial1: Errors: Framing 0, Parity 0, Overrun RX:2 (IF0:2), TX:0, Break 0
LOG: Serial1: Errors: Framing 0, Parity 0, Overrun RX:1 (IF0:1), TX:0, Break 0
VPX_PF_WATCH hit: lin=7000FA64 code=4 CS:EIP=00FF:000066D4 SS:ESP=0107:00017560
EAX=00000001 EBX=F000CA60 ECX=00000000 EDX=FFFFFFFF ESI=00017640 EDI=00017574 EBP=00017570
now=156820.191ms last serial RX 1.188ms ago deliveries=4961
code @EIP: 6A 00 57 53 56 FF 53 04 83 F8 00 0F 84 9C 07 00 00 8B 1B EB E6 6A 01 57
stack: 00017640 F000CA60 00017574 00000000 00120F92 0001000F 00000000 00000000 00000000 00000000
IVT match for EBX=F000CA60: INT00 INT06 INT07 INT2B INT2C INT2D INT32 INT34 INT35 INT36 INT37 INT38 INT39 INT3A INT3B INT3C INT3D INT3E INT3F INT40 INT42 INT44 INT45 INT47 INT48 INT49 INT4A INT4C INT4D INT4E INT4F INT50 INT51 INT52 INT53 INT54 INT55 INT56 INT57 INT58 INT59 INT5A INT5B INT5C INT5D INT5E INT5F INT66 INT68 INT69 INT6A INT6B INT6C INT6D INT6E INT6F
IVT[08-0F]: 0D1A0777 0D1A077B 0D1A077F 0D1A0783 0D1A0787 0D1A078B 0D1A078F 0D1A0793
ebp chain: [00017570]ret=0001000F
rx[ 0] t=156697.008 (123.183 ago) cs:eip=00FF:0042C978 byte=00
rx[ 1] t=156699.003 (121.189 ago) cs:eip=00FF:0044244C byte=00
rx[ 2] t=156700.003 (120.188 ago) cs:eip=00FF:00429109 byte=00
rx[ 3] t=156702.006 (118.185 ago) cs:eip=00FF:0042C98E byte=00
rx[ 4] t=156704.005 (116.186 ago) cs:eip=00FF:00442626 byte=00
rx[ 5] t=156705.003 (115.189 ago) cs:eip=00FF:00422A18 byte=00
rx[ 6] t=156707.003 (113.189 ago) cs:eip=0020:00001A21 byte=07
rx[ 7] t=156710.003 (110.188 ago) cs:eip=0D1A:00000A1E byte=FC
rx[ 8] t=156712.004 (108.187 ago) cs:eip=00FF:004CDFC8 byte=87
rx[ 9] t=156714.003 (106.189 ago) cs:eip=00FF:004CDFC8 byte=00
rx[ 10] t=156715.003 (105.189 ago) cs:eip=00FF:004CDFC8 byte=00
rx[ 11] t=156717.003 (103.188 ago) cs:eip=0020:0000101B byte=00
rx[ 12] t=156719.003 (101.189 ago) cs:eip=00FF:0045F505 byte=00
rx[ 13] t=156721.006 (99.185 ago) cs:eip=0020:000040A6 byte=00
rx[ 14] t=156723.003 (97.188 ago) cs:eip=00FF:004CDFC8 byte=00
rx[ 15] t=156725.004 (95.187 ago) cs:eip=00FF:004CDFC8 byte=00
rx[ 16] t=156727.003 (93.188 ago) cs:eip=00FF:00429386 byte=00
rx[ 17] t=156729.006 (91.185 ago) cs:eip=00FF:0042C978 byte=00
rx[ 18] t=156731.003 (89.188 ago) cs:eip=00FF:004423FB byte=00
rx[ 19] t=156733.005 (87.187 ago) cs:eip=00FF:00441928 byte=07
rx[ 20] t=156736.009 (84.182 ago) cs:eip=00FF:00410EF8 byte=FC
rx[ 21] t=156737.006 (83.185 ago) cs:eip=00FF:0042585D byte=87
rx[ 22] t=156739.004 (81.187 ago) cs:eip=00FF:004221B7 byte=00
rx[ 23] t=156741.007 (79.185 ago) cs:eip=00FF:00410629 byte=00
rx[ 24] t=156743.007 (77.185 ago) cs:eip=00FF:00410608 byte=00
rx[ 25] t=156745.003 (75.188 ago) cs:eip=00FF:0046D002 byte=00
rx[ 26] t=156748.003 (72.188 ago) cs:eip=00FF:004869EA byte=00
rx[ 27] t=156750.005 (70.187 ago) cs:eip=00FF:00425850 byte=00
rx[ 28] t=156751.003 (69.188 ago) cs:eip=00FF:004CE03E byte=00
rx[ 29] t=156754.003 (66.188 ago) cs:eip=00FF:0045F579 byte=00
rx[ 30] t=156755.013 (65.179 ago) cs:eip=00FF:0045F505 byte=00
rx[ 31] t=156757.006 (63.185 ago) cs:eip=0020:000047DA byte=00
rx[ 32] t=156759.004 (61.187 ago) cs:eip=00FF:004CE03E byte=07
rx[ 33] t=156761.004 (59.187 ago) cs:eip=00FF:004CE03E byte=FC
rx[ 34] t=156763.004 (57.187 ago) cs:eip=00FF:004CDFC8 byte=87
rx[ 35] t=156766.008 (54.183 ago) cs:eip=00FF:0042C978 byte=00
rx[ 36] t=156768.003 (52.189 ago) cs:eip=00FF:0044244C byte=00
rx[ 37] t=156769.003 (51.188 ago) cs:eip=00FF:00429109 byte=00
rx[ 38] t=156771.006 (49.185 ago) cs:eip=00FF:0042C98E byte=00
rx[ 39] t=156774.009 (46.182 ago) cs:eip=00FF:0042C978 byte=00
rx[ 40] t=156775.003 (45.188 ago) cs:eip=00FF:00442428 byte=00
rx[ 41] t=156778.004 (42.187 ago) cs:eip=00FF:00428B68 byte=00
rx[ 42] t=156780.003 (40.189 ago) cs:eip=00FF:004C427C byte=00
rx[ 43] t=156782.004 (38.187 ago) cs:eip=00FF:00425715 byte=00
rx[ 44] t=156784.003 (36.189 ago) cs:eip=0020:00000CB6 byte=00
rx[ 45] t=156786.005 (34.187 ago) cs:eip=00FF:004922BC byte=07
rx[ 46] t=156787.806 (32.385 ago) cs:eip=00FF:00492B48 byte=FC
rx[ 47] t=156789.008 (31.183 ago) cs:eip=00FF:0000B383 byte=87
rx[ 48] t=156791.004 (29.187 ago) cs:eip=00FF:004929E3 byte=00
rx[ 49] t=156793.903 (26.289 ago) cs:eip=00FF:00422BE0 byte=00
rx[ 50] t=156794.012 (26.179 ago) cs:eip=0020:00001738 byte=00
rx[ 51] t=156796.015 (24.177 ago) cs:eip=00FF:0045F505 byte=00
rx[ 52] t=156798.003 (22.189 ago) cs:eip=0D1A:00000B02 byte=00
rx[ 53] t=156800.004 (20.187 ago) cs:eip=00FF:004CE03E byte=00
rx[ 54] t=156802.003 (18.189 ago) cs:eip=00FF:004CDFC8 byte=00
rx[ 55] t=156804.003 (16.189 ago) cs:eip=00FF:004CE03E byte=00
rx[ 56] t=156807.004 (13.187 ago) cs:eip=00FF:004CE03E byte=00
rx[ 57] t=156808.004 (12.187 ago) cs:eip=00FF:004CE03E byte=00
rx[ 58] t=156810.004 (10.187 ago) cs:eip=00FF:004CDFC8 byte=07
rx[ 59] t=156812.004 (8.187 ago) cs:eip=00FF:004CDFC8 byte=FC
rx[ 60] t=156814.003 (6.189 ago) cs:eip=00FF:004CDFC8 byte=87
rx[ 61] t=156815.006 (5.185 ago) cs:eip=00FF:00425DA1 byte=00
rx[ 62] t=156818.004 (2.187 ago) cs:eip=00FF:0042C958 byte=00
rx[ 63] t=156819.003 (1.188 ago) cs:eip=00FF:0042C993 byte=00
VPX_PF_WATCH hit: lin=7000FA64 code=4 CS:EIP=00FF:000066D9 SS:ESP=0107:00017560
EAX=00000001 EBX=F000CA60 ECX=00000000 EDX=FFFFFFFF ESI=00017640 EDI=00017574 EBP=00017570
now=156821.021ms last serial RX 0.817ms ago deliveries=4962
code @EIP: FF 53 04 83 F8 00 0F 84 9C 07 00 00 8B 1B EB E6 6A 01 57 56 6A 02 6A 00
stack: 00017640 F000CA60 00017574 00000000 00120F92 0001000F 00000000 00000000 00000000 00000000
IVT match for EBX=F000CA60: INT00 INT06 INT07 INT2B INT2C INT2D INT32 INT34 INT35 INT36 INT37 INT38 INT39 INT3A INT3B INT3C INT3D INT3E INT3F INT40 INT42 INT44 INT45 INT47 INT48 INT49 INT4A INT4C INT4D INT4E INT4F INT50 INT51 INT52 INT53 INT54 INT55 INT56 INT57 INT58 INT59 INT5A INT5B INT5C INT5D INT5E INT5F INT66 INT68 INT69 INT6A INT6B INT6C INT6D INT6E INT6F
IVT[08-0F]: 0D1A0777 0D1A077B 0D1A077F 0D1A0783 0D1A0787 0D1A078B 0D1A078F 0D1A0793
ebp chain: [00017570]ret=0001000F
rx[ 0] t=156699.003 (122.019 ago) cs:eip=00FF:0044244C byte=00
rx[ 1] t=156700.003 (121.018 ago) cs:eip=00FF:00429109 byte=00
rx[ 2] t=156702.006 (119.015 ago) cs:eip=00FF:0042C98E byte=00
rx[ 3] t=156704.005 (117.016 ago) cs:eip=00FF:00442626 byte=00
rx[ 4] t=156705.003 (116.019 ago) cs:eip=00FF:00422A18 byte=00
rx[ 5] t=156707.003 (114.019 ago) cs:eip=0020:00001A21 byte=07
rx[ 6] t=156710.003 (111.018 ago) cs:eip=0D1A:00000A1E byte=FC
rx[ 7] t=156712.004 (109.017 ago) cs:eip=00FF:004CDFC8 byte=87
rx[ 8] t=156714.003 (107.019 ago) cs:eip=00FF:004CDFC8 byte=00
rx[ 9] t=156715.003 (106.019 ago) cs:eip=00FF:004CDFC8 byte=00
rx[ 10] t=156717.003 (104.018 ago) cs:eip=0020:0000101B byte=00
rx[ 11] t=156719.003 (102.019 ago) cs:eip=00FF:0045F505 byte=00
rx[ 12] t=156721.006 (100.015 ago) cs:eip=0020:000040A6 byte=00
rx[ 13] t=156723.003 (98.018 ago) cs:eip=00FF:004CDFC8 byte=00
rx[ 14] t=156725.004 (96.017 ago) cs:eip=00FF:004CDFC8 byte=00
rx[ 15] t=156727.003 (94.018 ago) cs:eip=00FF:00429386 byte=00
rx[ 16] t=156729.006 (92.015 ago) cs:eip=00FF:0042C978 byte=00
rx[ 17] t=156731.003 (90.018 ago) cs:eip=00FF:004423FB byte=00
rx[ 18] t=156733.005 (88.017 ago) cs:eip=00FF:00441928 byte=07
rx[ 19] t=156736.009 (85.012 ago) cs:eip=00FF:00410EF8 byte=FC
rx[ 20] t=156737.006 (84.015 ago) cs:eip=00FF:0042585D byte=87
rx[ 21] t=156739.004 (82.017 ago) cs:eip=00FF:004221B7 byte=00
rx[ 22] t=156741.007 (80.015 ago) cs:eip=00FF:00410629 byte=00
rx[ 23] t=156743.007 (78.015 ago) cs:eip=00FF:00410608 byte=00
rx[ 24] t=156745.003 (76.018 ago) cs:eip=00FF:0046D002 byte=00
rx[ 25] t=156748.003 (73.018 ago) cs:eip=00FF:004869EA byte=00
rx[ 26] t=156750.005 (71.017 ago) cs:eip=00FF:00425850 byte=00
rx[ 27] t=156751.003 (70.018 ago) cs:eip=00FF:004CE03E byte=00
rx[ 28] t=156754.003 (67.018 ago) cs:eip=00FF:0045F579 byte=00
rx[ 29] t=156755.013 (66.009 ago) cs:eip=00FF:0045F505 byte=00
rx[ 30] t=156757.006 (64.015 ago) cs:eip=0020:000047DA byte=00
rx[ 31] t=156759.004 (62.017 ago) cs:eip=00FF:004CE03E byte=07
rx[ 32] t=156761.004 (60.017 ago) cs:eip=00FF:004CE03E byte=FC
rx[ 33] t=156763.004 (58.017 ago) cs:eip=00FF:004CDFC8 byte=87
rx[ 34] t=156766.008 (55.013 ago) cs:eip=00FF:0042C978 byte=00
rx[ 35] t=156768.003 (53.019 ago) cs:eip=00FF:0044244C byte=00
rx[ 36] t=156769.003 (52.018 ago) cs:eip=00FF:00429109 byte=00
rx[ 37] t=156771.006 (50.015 ago) cs:eip=00FF:0042C98E byte=00
rx[ 38] t=156774.009 (47.012 ago) cs:eip=00FF:0042C978 byte=00
rx[ 39] t=156775.003 (46.018 ago) cs:eip=00FF:00442428 byte=00
rx[ 40] t=156778.004 (43.017 ago) cs:eip=00FF:00428B68 byte=00
rx[ 41] t=156780.003 (41.019 ago) cs:eip=00FF:004C427C byte=00
rx[ 42] t=156782.004 (39.017 ago) cs:eip=00FF:00425715 byte=00
rx[ 43] t=156784.003 (37.019 ago) cs:eip=0020:00000CB6 byte=00
rx[ 44] t=156786.005 (35.017 ago) cs:eip=00FF:004922BC byte=07
rx[ 45] t=156787.806 (33.215 ago) cs:eip=00FF:00492B48 byte=FC
rx[ 46] t=156789.008 (32.013 ago) cs:eip=00FF:0000B383 byte=87
rx[ 47] t=156791.004 (30.017 ago) cs:eip=00FF:004929E3 byte=00
rx[ 48] t=156793.903 (27.119 ago) cs:eip=00FF:00422BE0 byte=00
rx[ 49] t=156794.012 (27.009 ago) cs:eip=0020:00001738 byte=00
rx[ 50] t=156796.015 (25.007 ago) cs:eip=00FF:0045F505 byte=00
rx[ 51] t=156798.003 (23.019 ago) cs:eip=0D1A:00000B02 byte=00
rx[ 52] t=156800.004 (21.017 ago) cs:eip=00FF:004CE03E byte=00
rx[ 53] t=156802.003 (19.019 ago) cs:eip=00FF:004CDFC8 byte=00
rx[ 54] t=156804.003 (17.019 ago) cs:eip=00FF:004CE03E byte=00
rx[ 55] t=156807.004 (14.017 ago) cs:eip=00FF:004CE03E byte=00
rx[ 56] t=156808.004 (13.017 ago) cs:eip=00FF:004CE03E byte=00
rx[ 57] t=156810.004 (11.017 ago) cs:eip=00FF:004CDFC8 byte=07
rx[ 58] t=156812.004 (9.017 ago) cs:eip=00FF:004CDFC8 byte=FC
rx[ 59] t=156814.003 (7.019 ago) cs:eip=00FF:004CDFC8 byte=87
rx[ 60] t=156815.006 (6.015 ago) cs:eip=00FF:00425DA1 byte=00
rx[ 61] t=156818.004 (3.017 ago) cs:eip=00FF:0042C958 byte=00
rx[ 62] t=156819.003 (2.018 ago) cs:eip=00FF:0042C993 byte=00
rx[ 63] t=156820.204 (0.817 ago) cs:eip=0020:00001065 byte=00
LOG: 376707548 ERROR INT10:PutPixel unhandled mode type 7
LOG: SHELL:Redirect output to RC.TXT
LOG: Serial1: Errors: Framing 0, Parity 0, Overrun RX:484 (IF0:8), TX:0, Break 0
LOG: Serial1: Errors: Framing 0, Parity 0, Overrun RX:70 (IF0:0), TX:0, Break 0