Dolphin, the GameCube and Wii emulator - Forums

Full Version: Dolphin 4.0-7523: Spamming in logs, low performance
You're currently viewing a stripped down version of our content. View the full version with proper formatting.
Hi there. 

I came here today to ask for some help. You see, yesterday I downloaded the dev build mentioned in the title since to try the newest fixes implemented in the emulator. It worked fine then.

Today, I tried again and noticed that the games are slow as hell; and I did not change any settings. Well, only one; I turned on the "Show Log" option just to check what I could find in there. And I found out that there were lots of messages being spammed, slowing down gameplay!

I will post part of the spammed lines in here (as they appeared to me when emulating PAL version of Luigi´s Mansion):

57:35:820 NANDContentLoader.cpp:215 W[DIO]: CreateFromDirectory: error opening /title/00000001/00000002/content/title.tmd
58:27:769 HW\WiimoteReal\WiimoteReal.cpp:659 N[Wiimote]: WiimoteReal::Initialize
58:29:414 NANDContentLoader.cpp:215 W[DIO]: CreateFromDirectory: error opening /title/00000001/00000002/content/title.tmd
59:50:831 NANDContentLoader.cpp:215 W[DIO]: CreateFromDirectory: error opening /title/00000001/00000002/content/title.tmd
59:51:481 ConfigManager.cpp:85 N[BOOT]: Saving settings to C:/Users/franc_000/Documents/Dolphin Emulator/Config/Dolphin.ini
59:51:513 Core.cpp:858 W[COMMON]: Want determinism <- false
59:51:978 OpenALStream.cpp:34 W[Audio]: Found OpenAL device OpenAL Soft
59:52:033 Boot\Boot.cpp:224 N[BOOT]: Booting C:\Users\franc_000\Desktop\New folder/Luigi's Mansion.gcz
59:52:120 HLE\HLE_OS.cpp:46 N[OSREPORT]: 81200308->81300000| 
59:52:120 HLE\HLE_OS.cpp:46 N[OSREPORT]: 81200324->81300000| 
59:52:122 FileMonitor.cpp:110 W[FileMon]:       0 kB Kawano/s/CVS/
59:52:123 FileMonitor.cpp:110 W[FileMon]:       0 kB Map/CVS/
59:52:127 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 00000000 | WPL 40 | STD 40 | EQ 6 | PRB 503 | ACV 0 | PSB 4 | Field Even
59:52:127 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 0000 | fbwidth 0 | 8108100 | 8108100
59:52:149 OpenALStream.cpp:247 E[Audio]: Error unqueuing buffers: 0000a001
59:53:028 PowerPC\SignatureDB.cpp:126 E[HLE]: Wrong size! Found hioEnumCallback(long) at 801a9f70 (size: 0000001c instead of 0000000c)!
59:53:028 PowerPC\SignatureDB.cpp:126 E[HLE]: Wrong size! Found __DBExceptionDestination at 801e69ec (size: 0000002c instead of 00000010)!
59:53:028 PowerPC\SignatureDB.cpp:126 E[HLE]: Wrong size! Found SystemCallVector at 801e2018 (size: 00000084 instead of 00000020)!
59:53:028 PowerPC\SignatureDB.cpp:126 E[HLE]: Wrong size! Found cGameSFX::Init(void) at 801ad630 (size: 00000020 instead of 00000010)!
59:53:029 PowerPC\SignatureDB.cpp:126 E[HLE]: Wrong size! Found OSSwitchFPUContext at 801df620 (size: 000000cc instead of 00000084)!
59:53:029 PowerPC\SignatureDB.cpp:126 E[HLE]: Wrong size! Found OSLoadContext at 801df1b8 (size: 000000e0 instead of 000000d8)!
59:53:030 PowerPC\SignatureDB.cpp:126 E[HLE]: Wrong size! Found Reset at 801e0e84 (size: 000000b8 instead of 00000070)!
59:53:542 HW\EXI_DeviceIPL.cpp:282 N[OSREPORT]: 
59:53:543 HW\EXI_DeviceIPL.cpp:282 N[OSREPORT]: Dolphin OS $Revision: 49 $.
59:53:546 HW\EXI_DeviceIPL.cpp:282 N[OSREPORT]: Kernel built : Dec 17 2001 18:46:45
59:53:548 HW\EXI_DeviceIPL.cpp:282 N[OSREPORT]: Console Type : Development HW3
59:53:548 HW\EXI_DeviceIPL.cpp:282 N[OSREPORT]: Memory 24 MB
59:53:549 HW\EXI_DeviceIPL.cpp:282 N[OSREPORT]: Arena : 0x804db0e0 - 0x817faa80
59:53:566 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 00000000 | WPL 40 | STD 40 | EQ 6 | PRB 502 | ACV 0 | PSB 5 | Field Odd
59:53:566 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 0000 | fbwidth 0 | 8108100 | 8108100
59:53:660 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 00000000 | WPL 40 | STD 40 | EQ 6 | PRB 503 | ACV 0 | PSB 4 | Field Even
59:53:680 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 0000 | fbwidth 0 | 8108100 | 8108100
59:53:692 HW\EXI_DeviceIPL.cpp:282 N[OSREPORT]: app booted from bootrom
59:53:711 BPStructs.cpp:677 W[Video]: Unknown BP opcode: address = 0x00000069 value = 0x0000049e
59:53:711 BPStructs.cpp:677 W[Video]: Unknown BP opcode: address = 0x00000046 value = 0x0000024c
59:53:805 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 00000000 | WPL 40 | STD 40 | EQ 6 | PRB 502 | ACV 0 | PSB 5 | Field Odd
59:53:806 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 0000 | fbwidth 640 | 8108100 | 8108100
59:53:807 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 00568000 | WPL 40 | STD 80 | EQ 5 | PRB 585 | ACV 0 | PSB 25 | Field Odd
59:53:807 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 10f9 | fbwidth 640 | 9720000 | 9720000
59:53:846 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 00568000 | WPL 40 | STD 80 | EQ 5 | PRB 584 | ACV 0 | PSB 26 | Field Even
59:53:846 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 10f9 | fbwidth 640 | 9720000 | 9720000
59:54:611 HW\DSPHLE\UCodes\Zelda.cpp:111 W[DSPHLE]: Zelda UCode loaded, crc=42f64ac4, flags=00000284
59:54:611 HW\DSPHLE\UCodes\Zelda.cpp:381 N[DSPHLE]: Received a NOP command: 0
59:54:626 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 00568000 | WPL 40 | STD 80 | EQ 5 | PRB 585 | ACV 0 | PSB 25 | Field Odd
59:54:626 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 10f9 | fbwidth 640 | 9720000 | 9720000
59:54:647 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 0060D520 | WPL 40 | STD 80 | EQ 5 | PRB 584 | ACV 0 | PSB 26 | Field Even
59:54:647 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 10f9 | fbwidth 640 | 9720000 | 9720000
59:54:662 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 00568000 | WPL 40 | STD 80 | EQ 5 | PRB 59 | ACV 264 | PSB 23 | Field Odd
59:54:662 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 10f9 | fbwidth 640 | 9720000 | 9720000
59:54:668 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 0060D520 | WPL 40 | STD 80 | EQ 5 | PRB 58 | ACV 264 | PSB 24 | Field Even
59:54:668 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 10f9 | fbwidth 640 | 9720000 | 9720000
59:54:676 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 00568000 | WPL 40 | STD 80 | EQ 5 | PRB 59 | ACV 264 | PSB 23 | Field Odd
59:54:676 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 10f9 | fbwidth 640 | 9720000 | 9720000
59:54:695 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 0060D520 | WPL 40 | STD 80 | EQ 5 | PRB 58 | ACV 264 | PSB 24 | Field Even
59:54:695 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 10f9 | fbwidth 640 | 9720000 | 9720000
59:54:711 FileMonitor.cpp:110 W[FileMon]:     243 kB AudioRes/JaiInit.aaf
59:54:749 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 00568000 | WPL 40 | STD 80 | EQ 5 | PRB 59 | ACV 264 | PSB 23 | Field Odd
59:54:760 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 10f9 | fbwidth 640 | 9720000 | 9720000
59:54:772 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 0060D520 | WPL 40 | STD 80 | EQ 5 | PRB 58 | ACV 264 | PSB 24 | Field Even
59:54:772 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 10f9 | fbwidth 640 | 9720000 | 9720000
59:54:776 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 00568000 | WPL 40 | STD 80 | EQ 5 | PRB 59 | ACV 264 | PSB 23 | Field Odd
59:54:776 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 10f9 | fbwidth 640 | 9720000 | 9720000
59:54:781 FileMonitor.cpp:110 W[FileMon]:     256 kB AudioRes/Banks/LuiSe2_0.aw
59:54:784 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 0060D520 | WPL 40 | STD 80 | EQ 5 | PRB 58 | ACV 264 | PSB 24 | Field Even
59:54:784 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 10f9 | fbwidth 640 | 9720000 | 9720000
59:54:803 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 00568000 | WPL 40 | STD 80 | EQ 5 | PRB 59 | ACV 264 | PSB 23 | Field Odd
59:54:803 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 10f9 | fbwidth 640 | 9720000 | 9720000
59:54:825 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 0060D520 | WPL 40 | STD 80 | EQ 5 | PRB 58 | ACV 264 | PSB 24 | Field Even
59:54:825 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 10f9 | fbwidth 640 | 9720000 | 9720000
59:54:845 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 00568000 | WPL 40 | STD 80 | EQ 5 | PRB 59 | ACV 264 | PSB 23 | Field Odd
59:54:845 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 10f9 | fbwidth 640 | 9720000 | 9720000
59:54:863 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 0060D520 | WPL 40 | STD 80 | EQ 5 | PRB 58 | ACV 264 | PSB 24 | Field Even
59:54:863 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 10f9 | fbwidth 640 | 9720000 | 9720000
59:54:883 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 00568000 | WPL 40 | STD 80 | EQ 5 | PRB 59 | ACV 264 | PSB 23 | Field Odd
59:54:883 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 10f9 | fbwidth 640 | 9720000 | 9720000
59:54:907 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 0060D520 | WPL 40 | STD 80 | EQ 5 | PRB 58 | ACV 264 | PSB 24 | Field Even
59:54:907 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 10f9 | fbwidth 640 | 9720000 | 9720000
59:54:923 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 00568000 | WPL 40 | STD 80 | EQ 5 | PRB 59 | ACV 264 | PSB 23 | Field Odd
59:54:923 HW\VideoInterface.cpp:592 W[VI]: HorizScaling: 10f9 | fbwidth 640 | 9720000 | 9720000
59:54:944 HW\VideoInterface.cpp:588 W[VI]: (VI->BeginField): Address: 0060D520 | WPL 40 | STD 80 | EQ 5 | PRB 58 | ACV 264 | PSB 24 | Field Even

Sorry if it´s too long, and I´ll be waiting for your helpful responses. Thanks in advance.
These new messages were added by 4.0-7517. Disabling the logging (either by disabling VideoInterface logging or by setting logging to Error or Notice) should fix the performance if the problem indeed is caused by these messages being spammed. Let me know if it works.
Looks like a leftover from debugging. They should really be DEBUG_LOG instead of WARN_LOG.
Will try in a moment, thanks. Smile

EDIT: Just tried with both "Notice" and "Error" modes in the log; performance got back to normal. I also noticed that this line:

"Set Log Verbosity to Warning and attempt to load the game again to view the values"

appeared in the new logs that generated. Thanks a lot dudes!

EDIT 2: Now I got curious. What kind of values can be seen in the logs with the changes you mentioned? I mean, what is the purpose of them?
Yeah, using WARN_LOG instead of DEBUG_LOG sounds like a bug to me. I've asked booto to fix it, but if the issue is still there in some days, please open an issue report for it.

Edit: Already fixed in master. Thx for reporting.