Project

General

Profile

Emulator Issues #8365 » log_broke_5.0-10745.txt

Brokener - ZephyrSurfer, 07/08/2022 09:28 PM

 
53:40:449 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: Pushing 'next' menu 80065ab0 Accessory Test Menu
53:40:449 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: Done Pushing
53:40:449 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: processMenuChange() for menu id:6
53:40:449 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: Starting autotest for autoTestMenuID 6 (1 tests)
53:40:449 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: Starting auto test for menu Controller Test Menu
53:40:500 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:40:500 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:40:500 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:40:548 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:40:548 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:40:548 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:40:599 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:40:599 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:40:599 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:40:649 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:40:649 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:40:649 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:40:700 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:40:700 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:40:700 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:40:701 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: Autorun Menu:Controller Test Menu Test1 burnin:0
53:40:701 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]:
53:40:701 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: **Exec Controller Test diag /controller/controllerTest.dol**
53:40:701 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]:
53:40:701 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: FileIndex:129
53:40:702 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: Resetting menuID:6 Index:0
53:40:702 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: resetSys
53:40:812 core\hw\si\si_devicegccontroller.cpp:322 I[SI]: PAD 0 set to mode 0
53:40:814 core\hw\dvd\dvdinterface.cpp:920 I[DVD]: Read DiscID 00000000
53:40:964 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: dvdFsInit: entering function
53:40:964 core\hw\dvd\dvdinterface.cpp:911 I[DVD]: Read: DVDOffset=00000420, DMABuffer = 011149e0, SrcLength = 00000020, DMALength = 00000020
53:40:965 core\hw\dvd\dvdinterface.cpp:911 I[DVD]: Read: DVDOffset=00033000, DMABuffer = 00ff0000, SrcLength = 00004700, DMALength = 00004700
53:41:023 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]:
DL: Starting up
53:41:025 core\hw\dvd\dvdinterface.cpp:911 I[DVD]: Read: DVDOffset=4d650000, DMABuffer = 01114540, SrcLength = 00000020, DMALength = 00000020
53:41:025 core\hw\dvd\filemonitor.cpp:83 W[FileMon]: 0 kB disk.id
53:41:160 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]:
DL: Loading non artx diag /controller/controllerTest.dol
53:41:161 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]:
starting to read DOL header, filepos = <4cb48000>
53:41:161 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]:
Len:100 dol:81105738
53:41:162 core\hw\dvd\dvdinterface.cpp:911 I[DVD]: Read: DVDOffset=4cb48000, DMABuffer = 01114440, SrcLength = 00000100, DMALength = 00000100
53:41:162 core\hw\dvd\filemonitor.cpp:83 W[FileMon]: 362 kB controller/controllerTest.dol
53:41:222 core\hw\dvd\dvdinterface.cpp:911 I[DVD]: Read: DVDOffset=4cb48100, DMABuffer = 00003100, SrcLength = 00002560, DMALength = 00002560
53:41:223 core\hw\dvd\dvdinterface.cpp:911 I[DVD]: Read: DVDOffset=4cb4a660, DMABuffer = 00005660, SrcLength = 000428c0, DMALength = 000428c0
53:41:304 core\hw\dvd\dvdinterface.cpp:911 I[DVD]: Read: DVDOffset=4cb8cf20, DMABuffer = 00047f20, SrcLength = 00000020, DMALength = 00000020
53:41:304 core\hw\dvd\dvdinterface.cpp:911 I[DVD]: Read: DVDOffset=4cb8cf40, DMABuffer = 00047f40, SrcLength = 00000020, DMALength = 00000020
53:41:304 core\hw\dvd\dvdinterface.cpp:911 I[DVD]: Read: DVDOffset=4cb8cf60, DMABuffer = 00047f60, SrcLength = 000004c0, DMALength = 000004c0
53:41:304 core\hw\dvd\dvdinterface.cpp:911 I[DVD]: Read: DVDOffset=4cb8d420, DMABuffer = 00048420, SrcLength = 00012c80, DMALength = 00012c80
53:41:334 core\hw\dvd\dvdinterface.cpp:911 I[DVD]: Read: DVDOffset=4cba00a0, DMABuffer = 00062c00, SrcLength = 00000300, DMALength = 00000300
53:41:335 core\hw\dvd\dvdinterface.cpp:911 I[DVD]: Read: DVDOffset=4cba03a0, DMABuffer = 000633c0, SrcLength = 00000320, DMALength = 00000320
53:41:335 core\hw\dvd\dvdinterface.cpp:911 I[DVD]: Read: DVDOffset=00000420, DMABuffer = 01114940, SrcLength = 00000020, DMALength = 00000020
53:41:500 core\hw\dvd\dvdinterface.cpp:911 I[DVD]: Read: DVDOffset=00000440, DMABuffer = 01114960, SrcLength = 00000020, DMALength = 00000020
53:41:501 core\hw\dvd\dvdinterface.cpp:911 I[DVD]: Read: DVDOffset=00000440, DMABuffer = 017f9900, SrcLength = 00002000, DMALength = 00002000
53:41:501 core\hw\dvd\dvdinterface.cpp:911 I[DVD]: Read: DVDOffset=00033000, DMABuffer = 01000000, SrcLength = 00004700, DMALength = 00004700
53:41:559 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]:
<< Dolphin SDK - EXI debug build: Oct 29 2002 09:30:00 (0x2301) >>
53:41:563 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: << Dolphin SDK - SI debug build: Sep 5 2002 05:06:23 (0x2301) >>
53:41:565 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:41:568 core\hw\dsphle\ucodes\ucodes.cpp:228 I[DSPHLE]: Switching to ROM ucode
53:41:568 core\hw\dsphle\ucodes\rom.cpp:28 I[DSPHLE]: UCode_Rom - initialized
53:41:568 core\hw\dsphle\ucodes\ucodes.cpp:232 I[DSPHLE]: Switching to INIT ucode
53:41:568 core\hw\dsphle\ucodes\init.cpp:17 I[DSPHLE]: INITUCode - initialized
53:41:568 core\hw\dsphle\ucodes\ucodes.cpp:232 I[DSPHLE]: Switching to INIT ucode
53:41:568 core\hw\dsphle\ucodes\init.cpp:17 I[DSPHLE]: INITUCode - initialized
53:41:569 core\hw\dsphle\ucodes\ucodes.cpp:232 I[DSPHLE]: Switching to INIT ucode
53:41:569 core\hw\dsphle\ucodes\init.cpp:17 I[DSPHLE]: INITUCode - initialized
53:41:569 core\hw\dsphle\ucodes\ucodes.cpp:228 I[DSPHLE]: Switching to ROM ucode
53:41:569 core\hw\dsphle\ucodes\rom.cpp:28 I[DSPHLE]: UCode_Rom - initialized
53:41:569 core\powerpc\interpreter\interpreter_systemregisters.cpp:435 I[PowerPC]: DBAT updated 536 800001ff 0
53:41:573 core\powerpc\interpreter\interpreter_systemregisters.cpp:435 I[PowerPC]: DBAT updated 536 0 800001ff
53:41:575 core\powerpc\interpreter\interpreter_systemregisters.cpp:458 I[PowerPC]: IBAT updated 528 800001ff 0
53:41:576 core\powerpc\interpreter\interpreter_systemregisters.cpp:458 I[PowerPC]: IBAT updated 528 0 800001ff
53:41:577 core\powerpc\interpreter\interpreter_systemregisters.cpp:435 I[PowerPC]: DBAT updated 540 810000ff 0
53:41:579 core\powerpc\interpreter\interpreter_systemregisters.cpp:435 I[PowerPC]: DBAT updated 540 0 810000ff
53:41:581 core\powerpc\interpreter\interpreter_systemregisters.cpp:458 I[PowerPC]: IBAT updated 532 810000ff 0
53:41:582 core\powerpc\interpreter\interpreter_systemregisters.cpp:458 I[PowerPC]: IBAT updated 532 0 810000ff
53:41:590 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]:
53:41:591 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: Dolphin OS $Revision: 60 $.
53:41:593 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: Kernel built : Nov 5 2002 12:22:59
53:41:596 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: Console Type : Development HW3 (10000006)
53:41:596 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: Memory 24 MB
53:41:596 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: Arena : 0x80073700 - 0x81000000
53:41:596 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: << Dolphin SDK - OS debug build: Nov 5 2002 12:22:59 (0x2301) >>
53:41:610 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:41:612 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:41:612 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:41:612 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: << Dolphin SDK - DVD debug build: Oct 29 2002 09:31:01 (0x2301) >>
53:41:614 core\hw\dvd\dvdinterface.cpp:765 I[DVD]: DVDLowInquiry (Buffer 0x0005b920, 0x20)
53:41:616 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: Initializing OS
53:41:616 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: << Dolphin SDK - VI debug build: Sep 5 2002 05:06:29 (0x2301) >>
53:41:621 core\hw\si\si_devicegccontroller.cpp:81 I[SI]: PAD - Get Origin
53:41:623 core\hw\si\si_devicegccontroller.cpp:322 I[SI]: PAD 0 set to mode 3
53:41:631 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: << Dolphin SDK - GX debug build: Oct 29 2002 09:30:25 (0x2301) >>
53:41:698 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: Controller Test main
53:41:703 core\hw\processorinterface.cpp:112 W[PI]: Fifo reset (00000001)
53:41:703 core\hw\processorinterface.cpp:112 W[PI]: Fifo reset (00000000)
53:41:705 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: << Dolphin SDK - GX debug build: Oct 29 2002 09:30:25 (0x2301) >>
53:41:705 common\msghandler.cpp:115 E[MASTER]: Question: GFX FIFO: Unknown Opcode (0xff @ 000001B0FF1EAD1D, preprocess=false).
This means one of the following:
* The emulated GPU got desynced, disabling dual core can help
* Command stream corrupted by some spurious memory bug
* This really is an unknown opcode (unlikely)
* Some other sort of bug

Further errors will be sent to the Video Backend log and
Dolphin will now likely crash or hang. Enjoy.
53:43:803 common\msghandler.cpp:115 E[MASTER]: Question: Illegal command ff
CPBase: 0x0018b740
CPEnd: 0x001cb720
CPHiWatermark: 0x0003c000
CPLoWatermark: 0x00020000
CPReadWriteDistance: 0x00000040
CPWritePointer: 0x0018b780
CPReadPointer: 0x0018b740
CPBreakpoint: 0x00000000
bFF_GPReadEnable: true
bFF_BPEnable: false
bFF_BPInt: false
bFF_Breakpoint: false
bFF_GPLinkEnable: true
bFF_HiWatermarkInt: true
bFF_LoWatermarkInt: false

53:44:572 videocommon\opcodedecoding.cpp:241 E[Video]: FIFO: Unknown Opcode(0xff @ 000001B0FF1EAD1D, preprocessing = no)
53:44:600 core\hw\dvd\dvdinterface.cpp:911 I[DVD]: Read: DVDOffset=4ca08000, DMABuffer = 001eb8a0, SrcLength = 00080000, DMALength = 00080000
53:44:600 core\hw\dvd\filemonitor.cpp:83 W[FileMon]: 1,297 kB controller/cont.tpl
53:44:860 core\hw\dvd\dvdinterface.cpp:911 I[DVD]: Read: DVDOffset=4ca88000, DMABuffer = 0026b8a0, SrcLength = 00080000, DMALength = 00080000
53:45:017 core\hw\dvd\dvdinterface.cpp:911 I[DVD]: Read: DVDOffset=4cb08000, DMABuffer = 002eb8a0, SrcLength = 0003cd00, DMALength = 0003cd00
53:45:099 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:099 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:099 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:155 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:155 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:155 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:204 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:204 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:204 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:254 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:254 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:254 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:305 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:305 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:305 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:354 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:354 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:355 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:405 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:406 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:406 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:456 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:456 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:456 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:506 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:506 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:506 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:556 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:556 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:556 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:605 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:605 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:605 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(3) != actual_response_length(4): request: 00
53:45:640 core\hw\exi\exi_deviceipl.cpp:302 N[OSREPORT]: type = <150994944>
53:45:641 core\hw\si\si_devicegccontroller.cpp:107 E[SI]: Unknown SI command (0x43)
53:45:641 common\msghandler.cpp:115 E[MASTER]: Question: SI: Unknown command (0x43)
55:09:001 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(10) != actual_response_length(0): request: 43 00 00
55:09:001 core\hw\si\si_devicegccontroller.cpp:107 E[SI]: Unknown SI command (0x43)
55:09:001 common\msghandler.cpp:115 E[MASTER]: Question: SI: Unknown command (0x43)
55:35:611 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(10) != actual_response_length(0): request: 43 00 00
55:35:611 core\hw\si\si_devicegccontroller.cpp:107 E[SI]: Unknown SI command (0x43)
55:35:611 common\msghandler.cpp:115 E[MASTER]: Question: SI: Unknown command (0x43)
55:37:176 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(10) != actual_response_length(0): request: 43 00 00
55:37:176 core\hw\si\si_devicegccontroller.cpp:107 E[SI]: Unknown SI command (0x43)
55:37:176 common\msghandler.cpp:115 E[MASTER]: Question: SI: Unknown command (0x43)
55:37:817 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(10) != actual_response_length(0): request: 43 00 00
55:37:817 core\hw\si\si_devicegccontroller.cpp:107 E[SI]: Unknown SI command (0x43)
55:37:817 common\msghandler.cpp:115 E[MASTER]: Question: SI: Unknown command (0x43)
55:38:385 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(10) != actual_response_length(0): request: 43 00 00
55:38:385 core\hw\si\si_devicegccontroller.cpp:107 E[SI]: Unknown SI command (0x43)
55:38:385 common\msghandler.cpp:115 E[MASTER]: Question: SI: Unknown command (0x43)
55:38:935 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(10) != actual_response_length(0): request: 43 00 00
55:38:935 core\hw\si\si_devicegccontroller.cpp:107 E[SI]: Unknown SI command (0x43)
55:38:935 common\msghandler.cpp:115 E[MASTER]: Question: SI: Unknown command (0x43)
55:39:441 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(10) != actual_response_length(0): request: 43 00 00
55:39:441 core\hw\si\si_devicegccontroller.cpp:107 E[SI]: Unknown SI command (0x43)
55:39:441 common\msghandler.cpp:115 E[MASTER]: Question: SI: Unknown command (0x43)
55:39:973 core\hw\si\si.cpp:318 E[SI]: RunSIBuffer: expected_response_length(10) != actual_response_length(0): request: 43 00 00
55:39:973 core\hw\si\si_devicegccontroller.cpp:107 E[SI]: Unknown SI command (0x43)
55:39:973 common\msghandler.cpp:115 E[MASTER]: Question: SI: Unknown command (0x43)
(2-2/2)