Deadlock since commit 61442d6

Andrei_ME · August 26, 2017, 2:07am

Issue:
Since the commit 61442d6, the game Mario & Luigi - Dream Team Bros deadlocks when a fight starts, that is, the game hangs, uses 0%of CPU

System Information

Operating System: Manjaro Linux, kernel 4.12.8
CPU: Intel Core i7-3612QM
GPU:
Citra Version (found in title bar): 61442d6, 3cdf854
Game: Mario & Luigi - Dream Team Bros
Screenshot of Issue (include the full Citra window including titlebar):

Log:
[ 0.000000] Frontend citra_qt/main.cpp:BootGame:382: Citra starting… [ 0.012322] Service.APT core/hle/service/apt/apt.cpp:Init:1001: Loaded shared font by legacy method [ 0.012633] Render.OpenGL video_core/renderer_opengl/renderer_opengl.cpp:Init:488: GL_VERSION: 4.2 (Core Profile) Mesa 17.1.6 [ 0.012650] Render.OpenGL video_core/renderer_opengl/renderer_opengl.cpp:Init:489: GL_VENDOR: Intel Open Source Technology Center [ 0.012658] Render.OpenGL video_core/renderer_opengl/renderer_opengl.cpp:Init:490: GL_RENDERER: Mesa DRI Intel® Ivybridge Mobile [ 0.018084] Loader core/loader/ncch.cpp:Load:350: Program ID: 00040000000D9000 [ 0.049459] Loader core/hle/kernel/process.cpp:ParseKernelCaps:108: ExHeader kernel version: 2.33 [ 0.049897] Service.CFG core/hle/service/cfg/cfg.cpp:SetPreferredRegionCode:613: Preferred region code set to 2 [ 0.325676] Service.SRV core/hle/service/sm/srv.cpp:RegisterClient:47: (STUBBED) called [ 0.326156] Service.SRV core/hle/service/sm/srv.cpp:EnableNotification:69: (STUBBED) called [ 0.329700] Service.APT core/hle/service/apt/apt.cpp:GetLockHandle:261: (STUBBED) called handle=0x00030008 applet_attributes=0x00000000 [ 0.337908] Service.NDM core/hle/service/ndm/ndm.cpp:OverrideDefaultDaemons:203: (STUBBED) default_daemon_bit_mask=0x0000000F [ 0.338160] Service.NDM core/hle/service/ndm/ndm.cpp:SuspendDaemons:89: (STUBBED) daemon_bit_mask=0x00000009 [ 0.339516] Service.APT core/hle/service/apt/apt.cpp:NotifyToWait:238: (STUBBED) app_id=768 [ 0.344068] Service.APT core/hle/service/apt/apt.cpp:AppletUtility:565: (STUBBED) called command=0x00000007, input_size=0x00000004, output_size=0x00000001, input_addr=0x0FFFFEE0, output_addr=0x0FFFFEAC [ 0.344654] Service.APT core/hle/service/apt/apt.cpp:AppletUtility:565: (STUBBED) called command=0x00000004, input_size=0x00000001, output_size=0x00000001, input_addr=0x0FFFFEA8, output_addr=0x0FFFFEAC [ 0.353480] Service.FS core/hle/service/fs/fs_user.cpp:InitializeWithSdkVersion:806: (STUBBED) called, version: 0x040205C8 [ 0.381035] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:LoadCRR:202: (STUBBED) called, crr_buffer_ptr=0x0801A000, crr_size=0x00001000, process=0xFFFF8001 [ 0.383162] Service.DSP core/hle/service/dsp_dsp.cpp:LoadComponent:148: Firmware hash: 0xc4673b93fcea5419 [ 0.383184] Service.DSP core/hle/service/dsp_dsp.cpp:LoadComponent:152: Structures hash: 0x93e48663943cad39 [ 0.383195] Service.DSP core/hle/service/dsp_dsp.cpp:LoadComponent:157: (STUBBED) called size=0xC234, prog_mask=0x000000FF, data_mask=0x000700FF, buffer=0x006D5F2C [ 0.384299] Service.DSP core/hle/service/dsp_dsp.cpp:RegisterInterruptEvents:248: Registered type=2, pipe=2, event_handle=0x0007801C [ 0.384758] Service.DSP core/hle/service/dsp_dsp.cpp:GetSemaphoreEventHandle:174: (STUBBED) called [ 0.385164] Service.DSP core/hle/service/dsp_dsp.cpp:SetSemaphoreMask:469: (STUBBED) called mask=0x00002000 [ 0.385829] Audio.DSP audio_core/hle/pipe.cpp:PipeWrite:134: Application has requested initialization of DSP hardware [ 0.386120] Service.DSP core/hle/service/dsp_dsp.cpp:SetSemaphore:271: (STUBBED) called [ 0.388880] Service.DSP core/hle/service/dsp_dsp.cpp:SetSemaphore:271: (STUBBED) called [ 0.451251] Service.FS core/hle/service/fs/archive.cpp:HandleSyncRequest:171: (STUBBED) File command OpenLinkFile Path: [Binary: 000000000000000000000000] [ 0.499797] Service.GSP core/hle/service/gsp_gpu.cpp:AcquireRight:702: called [ 0.500914] Service.GSP core/hle/service/gsp_gpu.cpp:RegisterInterruptRelayQueue:397: called, flags=0x00000001 [ 0.597953] Service.APT core/hle/service/apt/apt.cpp:AppletUtility:565: (STUBBED) called command=0x00000004, input_size=0x00000001, output_size=0x00000001, input_addr=0x0FFFFF48, output_addr=0x0FFFFF4C [ 0.641341] Service.LDR core/hle/service/ldr_ro/cro_helper.cpp:ApplyStaticAnonymousSymbolToCRS:528: CRO “Title” exports 0 static anonymous symbols [ 0.642267] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:LoadCRO:445: CRO “Title” loaded at 0x00730000, fixed_end=0x0076D000 [ 1.565156] Service.FS core/hle/service/fs/archive.cpp:HandleSyncRequest:171: (STUBBED) File command OpenLinkFile Path: [Binary: 000000000000000000000000] [ 5.689508] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:UnloadCRO:501: Unloading CRO “Title” [ 5.723627] Service.LDR core/hle/service/ldr_ro/cro_helper.cpp:ApplyStaticAnonymousSymbolToCRS:528: CRO “Load” exports 0 static anonymous symbols [ 5.724486] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:LoadCRO:445: CRO “Load” loaded at 0x00730000, fixed_end=0x0075A000 [ 8.795685] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:UnloadCRO:501: Unloading CRO “Load” [ 8.831537] Service.LDR core/hle/service/ldr_ro/cro_helper.cpp:ApplyStaticAnonymousSymbolToCRS:528: CRO “FReal” exports 0 static anonymous symbols [ 8.831596] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:LoadCRO:445: CRO “FReal” loaded at 0x00730000, fixed_end=0x00732000 [ 66.865974] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:UnloadCRO:501: Unloading CRO “FReal” [ 66.912636] Service.LDR core/hle/service/ldr_ro/cro_helper.cpp:ApplyStaticAnonymousSymbolToCRS:528: CRO “FDream” exports 0 static anonymous symbols [ 66.912700] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:LoadCRO:445: CRO “FDream” loaded at 0x00730000, fixed_end=0x00732000 ^C^CDead (I had to kill the process)

Andrei_ME · August 26, 2017, 2:11am

That’s the log from the last working version, 2bbff9f:
[ 0.000000] Frontend citra_qt/main.cpp:BootGame:382: Citra starting… [ 0.023722] Service.APT core/hle/service/apt/apt.cpp:Init:1001: Loaded shared font by legacy method [ 0.024054] Render.OpenGL video_core/renderer_opengl/renderer_opengl.cpp:Init:488: GL_VERSION: 4.2 (Core Profile) Mesa 17.1.6 [ 0.024064] Render.OpenGL video_core/renderer_opengl/renderer_opengl.cpp:Init:489: GL_VENDOR: Intel Open Source Technology Center [ 0.024068] Render.OpenGL video_core/renderer_opengl/renderer_opengl.cpp:Init:490: GL_RENDERER: Mesa DRI Intel® Ivybridge Mobile [ 0.029685] Loader core/loader/ncch.cpp:Load:350: Program ID: 00040000000D9000 [ 0.068029] Loader core/hle/kernel/process.cpp:ParseKernelCaps:108: ExHeader kernel version: 2.33 [ 0.068446] Service.CFG core/hle/service/cfg/cfg.cpp:SetPreferredRegionCode:613: Preferred region code set to 2 [ 0.326581] Service.SRV core/hle/service/sm/srv.cpp:RegisterClient:47: (STUBBED) called [ 0.327086] Service.SRV core/hle/service/sm/srv.cpp:EnableNotification:69: (STUBBED) called [ 0.330571] Service.APT core/hle/service/apt/apt.cpp:GetLockHandle:261: (STUBBED) called handle=0x00030008 applet_attributes=0x00000000 [ 0.338517] Service.NDM core/hle/service/ndm/ndm.cpp:OverrideDefaultDaemons:203: (STUBBED) default_daemon_bit_mask=0x0000000F [ 0.338745] Service.NDM core/hle/service/ndm/ndm.cpp:SuspendDaemons:89: (STUBBED) daemon_bit_mask=0x00000009 [ 0.340051] Service.APT core/hle/service/apt/apt.cpp:NotifyToWait:238: (STUBBED) app_id=768 [ 0.344614] Service.APT core/hle/service/apt/apt.cpp:AppletUtility:565: (STUBBED) called command=0x00000007, input_size=0x00000004, output_size=0x00000001, input_addr=0x0FFFFEE0, output_addr=0x0FFFFEAC [ 0.345182] Service.APT core/hle/service/apt/apt.cpp:AppletUtility:565: (STUBBED) called command=0x00000004, input_size=0x00000001, output_size=0x00000001, input_addr=0x0FFFFEA8, output_addr=0x0FFFFEAC [ 0.353577] Service.FS core/hle/service/fs/fs_user.cpp:InitializeWithSdkVersion:806: (STUBBED) called, version: 0x040205C8 [ 0.380864] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:LoadCRR:202: (STUBBED) called, crr_buffer_ptr=0x0801A000, crr_size=0x00001000, process=0xFFFF8001 [ 0.382818] Service.DSP core/hle/service/dsp_dsp.cpp:LoadComponent:148: Firmware hash: 0xc4673b93fcea5419 [ 0.382842] Service.DSP core/hle/service/dsp_dsp.cpp:LoadComponent:152: Structures hash: 0x93e48663943cad39 [ 0.382846] Service.DSP core/hle/service/dsp_dsp.cpp:LoadComponent:157: (STUBBED) called size=0xC234, prog_mask=0x000000FF, data_mask=0x000700FF, buffer=0x006D5F2C [ 0.383908] Service.DSP core/hle/service/dsp_dsp.cpp:RegisterInterruptEvents:248: Registered type=2, pipe=2, event_handle=0x0007801C [ 0.384372] Service.DSP core/hle/service/dsp_dsp.cpp:GetSemaphoreEventHandle:174: (STUBBED) called [ 0.384784] Service.DSP core/hle/service/dsp_dsp.cpp:SetSemaphoreMask:469: (STUBBED) called mask=0x00002000 [ 0.385426] Audio.DSP audio_core/hle/pipe.cpp:PipeWrite:134: Application has requested initialization of DSP hardware [ 0.385715] Service.DSP core/hle/service/dsp_dsp.cpp:SetSemaphore:271: (STUBBED) called [ 0.388438] Service.DSP core/hle/service/dsp_dsp.cpp:SetSemaphore:271: (STUBBED) called [ 0.450691] Service.FS core/hle/service/fs/archive.cpp:HandleSyncRequest:171: (STUBBED) File command OpenLinkFile Path: [Binary: 000000000000000000000000] [ 0.499259] Service.GSP core/hle/service/gsp_gpu.cpp:AcquireRight:702: called [ 0.500377] Service.GSP core/hle/service/gsp_gpu.cpp:RegisterInterruptRelayQueue:397: called, flags=0x00000001 [ 0.597284] Service.APT core/hle/service/apt/apt.cpp:AppletUtility:565: (STUBBED) called command=0x00000004, input_size=0x00000001, output_size=0x00000001, input_addr=0x0FFFFF48, output_addr=0x0FFFFF4C [ 0.641226] Service.LDR core/hle/service/ldr_ro/cro_helper.cpp:ApplyStaticAnonymousSymbolToCRS:528: CRO “Title” exports 0 static anonymous symbols [ 0.642123] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:LoadCRO:445: CRO “Title” loaded at 0x00730000, fixed_end=0x0076D000 [ 1.574247] Service.FS core/hle/service/fs/archive.cpp:HandleSyncRequest:171: (STUBBED) File command OpenLinkFile Path: [Binary: 000000000000000000000000] [ 6.714781] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:UnloadCRO:501: Unloading CRO “Title” [ 6.751518] Service.LDR core/hle/service/ldr_ro/cro_helper.cpp:ApplyStaticAnonymousSymbolToCRS:528: CRO “Load” exports 0 static anonymous symbols [ 6.752321] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:LoadCRO:445: CRO “Load” loaded at 0x00730000, fixed_end=0x0075A000 [ 9.580967] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:UnloadCRO:501: Unloading CRO “Load” [ 9.615126] Service.LDR core/hle/service/ldr_ro/cro_helper.cpp:ApplyStaticAnonymousSymbolToCRS:528: CRO “FReal” exports 0 static anonymous symbols [ 9.615184] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:LoadCRO:445: CRO “FReal” loaded at 0x00730000, fixed_end=0x00732000 [ 56.357083] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:UnloadCRO:501: Unloading CRO “FReal” [ 56.404455] Service.LDR core/hle/service/ldr_ro/cro_helper.cpp:ApplyStaticAnonymousSymbolToCRS:528: CRO “FDream” exports 0 static anonymous symbols [ 56.404509] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:LoadCRO:445: CRO “FDream” loaded at 0x00730000, fixed_end=0x00732000 [ 71.241672] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:UnloadCRO:501: Unloading CRO “FDream” [ 71.287579] Service.LDR core/hle/service/ldr_ro/cro_helper.cpp:ApplyStaticAnonymousSymbolToCRS:528: CRO “Menu” exports 0 static anonymous symbols [ 71.288803] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:LoadCRO:445: CRO “Menu” loaded at 0x00730000, fixed_end=0x0078C000 [ 71.495487] Service core/hle/service/service.cpp:HandleSyncRequest:95: unknown / unimplemented function ‘GetStepHistory’: port=ptm:u, cmd_buff[1]=0x18, cmd_buff[2]=0xABE08800, cmd_buff[3]=0x81, cmd_buff[4]=0x30C, cmd_buff[5]=0xFFFFDF0 [ 85.606845] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:UnloadCRO:501: Unloading CRO “Menu” [ 85.648060] Service.LDR core/hle/service/ldr_ro/cro_helper.cpp:ApplyStaticAnonymousSymbolToCRS:528: CRO “FDream” exports 0 static anonymous symbols [ 85.648112] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:LoadCRO:445: CRO “FDream” loaded at 0x00730000, fixed_end=0x00732000 [ 94.948023] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:UnloadCRO:501: Unloading CRO “FDream” [ 95.120454] Service.LDR core/hle/service/ldr_ro/cro_helper.cpp:ApplyStaticAnonymousSymbolToCRS:528: CRO “BNormal” exports 0 static anonymous symbols [ 95.120506] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:LoadCRO:445: CRO “BNormal” loaded at 0x00730000, fixed_end=0x00732000 [ 95.338531] Service.HID core/hle/service/hid/hid.cpp:GetGyroscopeLowCalibrateParam:366: (STUBBED) called [ 95.403053] Service core/hle/service/service.cpp:HandleSyncRequest:95: unknown / unimplemented function ‘GetStepHistory’: port=ptm:u, cmd_buff[1]=0x18, cmd_buff[2]=0xABE08800, cmd_buff[3]=0x81, cmd_buff[4]=0x30C, cmd_buff[5]=0xFFFFE60 [ 108.080037] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:UnloadCRO:501: Unloading CRO “BNormal” [ 108.127705] Service.LDR core/hle/service/ldr_ro/cro_helper.cpp:ApplyStaticAnonymousSymbolToCRS:528: CRO “FDream” exports 0 static anonymous symbols [ 108.127751] Service.LDR core/hle/service/ldr_ro/ldr_ro.cpp:LoadCRO:445: CRO “FDream” loaded at 0x00730000, fixed_end=0x00732000

Adityarup_Laha · August 26, 2017, 6:03am

Something is wrong with the CRO Object. The devs will be able to tell u better.

Selby · August 26, 2017, 6:19am

CROs are just dynamically loaded code - there could be a hundred million things going on, and I doubt our CRO implementation is the issue.

Adityarup_Laha · August 26, 2017, 6:19am

OK sorry, my bad. Wt do u think is wrong ?

RavenHome · August 26, 2017, 10:13am

this could be a regression issue, can you open up a ticket about it in github

Andrei_ME · August 26, 2017, 5:21pm

Okz, I opened a ticket for regression in github, thanks

CodingKoopa · August 27, 2017, 3:45pm

I’m going to untick that as a solution because that still doesn’t really solve the problem.

RavenHome · August 30, 2017, 3:38pm

should be fixed in the latest nightly

Andrei_ME · August 30, 2017, 6:04pm

Yes, it is, I have tested the commit, now just have to wait the nightly build to be built, thanks everyone

Leo121 · August 30, 2017, 6:17pm

Ticking this as solved. The PR that fixed this issue has been merged but it’s not in current nightly builds. It should be in the next nightly whenever a commit is pushed to master.