Mario & Luigi: Dream Team unmapped read after encountering inky piranha plant


#1

Issue:
In Mario & Luigi: Dream Team, if inky piranha plant (a background enemy) appears in battle, after the battle ends, opening the menu or trying to save will freeze the game

System Information

  • Operating System: win10
  • CPU: i7 6700k
  • GPU: gtx980
  • Citra Version (found in titlebar): master-ad4097e7
  • Game: Mario & Luigi: Dream Team
  • Screenshot of Issue (include the full Citra window including titlebar):
    the black flower in the background is inky piranha plant

    Log:
    [ 0.000487] Common.Filesystem common\file_util.cpp:FileUtil::CreateFullPath:200: path exists C:\Users\Kabosu\AppData\Roaming/Citra/config/qt-config.ini
    [ 6.568543] Frontend citra_qt\main.cpp:GMainWindow::BootGame:373: Citra starting…
    [ 6.924455] Loader core\loader\loader.cpp:Loader::GetLoader:142: Loading file D:/game/3ds/0295 - Mario & Luigi - Dream Team Bros. (Europe) (En,Fr,De,Es,It,Nl,Pt,Ru) Decrypted.3ds as NCSD…
    [ 6.924673] Loader core\loader\ncch.cpp:Loader::AppLoader_NCCH::LoadExeFS:256: Only loading the first (bootable) NCCH within the NCSD file!
    [ 6.924771] Loader core\loader\ncch.cpp:Loader::AppLoader_NCCH::LoadExeFS:280: Name: MILLI4C
    [ 6.924868] Loader core\loader\ncch.cpp:Loader::AppLoader_NCCH::LoadExeFS:281: Program ID: 00040000000D9000
    [ 6.928906] Service.FS core\file_sys\archive_sdmc.cpp:FileSys::ArchiveFactory_SDMC::ArchiveFactory_SDMC:309: Directory C:\Users\Kabosu\AppData\Roaming/Citra/sdmc/ set as SDMC.
    [ 6.929249] Common.Filesystem common\file_util.cpp:FileUtil::CreateFullPath:200: path exists C:\Users\Kabosu\AppData\Roaming/Citra/sdmc/
    [ 6.929321] Service.FS core\file_sys\archive_sdmcwriteonly.cpp:FileSys::ArchiveFactory_SDMCWriteOnly::ArchiveFactory_SDMCWriteOnly:35: Directory C:\Users\Kabosu\AppData\Roaming/Citra/sdmc/ set as SDMCWriteOnly.
    [ 6.929460] Common.Filesystem common\file_util.cpp:FileUtil::CreateFullPath:200: path exists C:\Users\Kabosu\AppData\Roaming/Citra/sdmc/
    [ 6.929593] Service.FS core\file_sys\archive_source_sd_savedata.cpp:FileSys::ArchiveSource_SDSaveData::ArchiveSource_SDSaveData:42: Directory C:\Users\Kabosu\AppData\Roaming/Citra/sdmc/Nintendo 3DS/00000000000000000000000000000000/00000000000000000000000000000000/title/ set as SaveData.
    [ 6.930040] Service.FS core\file_sys\archive_extsavedata.cpp:FileSys::ArchiveFactory_ExtSaveData::ArchiveFactory_ExtSaveData:176: Directory C:\Users\Kabosu\AppData\Roaming/Citra/sdmc/Nintendo 3DS/00000000000000000000000000000000/00000000000000000000000000000000/extdata/ set as base for ExtSaveData.
    [ 6.930428] Common.Filesystem common\file_util.cpp:FileUtil::CreateFullPath:200: path exists C:\Users\Kabosu\AppData\Roaming/Citra/sdmc/Nintendo 3DS/00000000000000000000000000000000/00000000000000000000000000000000/extdata/
    [ 6.930808] Service.FS core\file_sys\archive_extsavedata.cpp:FileSys::ArchiveFactory_ExtSaveData::ArchiveFactory_ExtSaveData:176: Directory C:\Users\Kabosu\AppData\Roaming/Citra/nand/data/00000000000000000000000000000000/extdata/ set as base for ExtSaveData.
    [ 6.931300] Common.Filesystem common\file_util.cpp:FileUtil::CreateFullPath:200: path exists C:\Users\Kabosu\AppData\Roaming/Citra/nand/data/00000000000000000000000000000000/extdata/
    [ 6.931831] Service.APT core\hle\service\apt\apt.cpp:Service::APT::Init:627: Unable to load shared font: C:\Users\Kabosu\AppData\Roaming/Citra/sysdata/shared_font.bin
    [ 6.932548] Render.OpenGL video_core\renderer_opengl\renderer_opengl.cpp:RendererOpenGL::Init:490: GL_VERSION: 3.3.0 NVIDIA 376.33
    [ 6.933656] Render.OpenGL video_core\renderer_opengl\renderer_opengl.cpp:RendererOpenGL::Init:491: GL_VENDOR: NVIDIA Corporation
    [ 6.934052] Render.OpenGL video_core\renderer_opengl\renderer_opengl.cpp:RendererOpenGL::Init:492: GL_RENDERER: GeForce GTX 980/PCIe/SSE2
    [ 6.962522] Loader core\hle\kernel\process.cpp:Kernel::Process::ParseKernelCaps:99: ExHeader kernel version: 2.33
    [ 6.964086] Service.CFG core\hle\service\cfg\cfg.cpp:Service::CFG::SetPreferredRegionCode:582: Preferred region code set to 2
    [ 7.097858] Service.SRV core\hle\service\srv.cpp:Service::SRV::RegisterClient:40: (STUBBED) called
    [ 7.098994] Service.SRV core\hle\service\srv.cpp:Service::SRV::EnableNotification:64: (STUBBED) called
    [ 7.101534] Service.APT core\hle\service\apt\apt.cpp:Service::APT::GetLockHandle:122: (STUBBED) called handle=0x00030008 applet_attributes=0x00000000
    [ 7.104726] Service.NDM core\hle\service\ndm\ndm.cpp:Service::NDM::OverrideDefaultDaemons:201: (STUBBED) default_daemon_bit_mask=0x0000000F
    [ 7.106125] Service.NDM core\hle\service\ndm\ndm.cpp:Service::NDM::SuspendDaemons:87: (STUBBED) daemon_bit_mask=0x00000009
    [ 7.107167] Service.APT core\hle\service\apt\apt.cpp:Service::APT::Enable:130: (STUBBED) called attributes=0x00000000
    [ 7.108327] Service.APT core\hle\service\apt\apt.cpp:Service::APT::GlanceParameter:249: called app_id=0x00000300, buffer_size=0x00001000
    [ 7.109200] Service.APT core\hle\service\apt\apt.cpp:Service::APT::NotifyToWait:104: (STUBBED) app_id=768
    [ 7.110263] Service.APT core\hle\service\apt\apt.cpp:Service::APT::ReceiveParameter:226: called app_id=0x00000300, buffer_size=0x00001000
    [ 7.111557] Service.APT core\hle\service\apt\apt.cpp:Service::APT::AppletUtility:320: (STUBBED) called command=0x00000007, buffer1_size=0x00000004, buffer2_size=0x00000001, buffer1_addr=0x0FFFFEE0, buffer2_addr=0x0FFFFEAC
    [ 7.112041] Service.APT core\hle\service\apt\apt.cpp:Service::APT::AppletUtility:320: (STUBBED) called command=0x00000004, buffer1_size=0x00000001, buffer2_size=0x00000001, buffer1_addr=0x0FFFFEA8, buffer2_addr=0x0FFFFEAC
    [ 7.115405] Service.FS core\hle\service\fs\fs_user.cpp:Service::FS::InitializeWithSdkVersion:801: (STUBBED) called, version: 0x040205C8
    [ 7.126761] Service.LDR core\hle\service\ldr_ro\ldr_ro.cpp:Service::LDR::LoadCRR:217: (STUBBED) called, crr_buffer_ptr=0x0801A000, crr_size=0x00001000, descriptor=0x00000000, process=0xFFFF8001
    [ 7.128447] Service.DSP core\hle\service\dsp_dsp.cpp:Service::DSP_DSP::LoadComponent:142: Firmware hash: 0xc4673b93fcea5419
    [ 7.129220] Service.DSP core\hle\service\dsp_dsp.cpp:Service::DSP_DSP::LoadComponent:146: Structures hash: 0x93e48663943cad39
    [ 7.129639] Service.DSP core\hle\service\dsp_dsp.cpp:Service::DSP_DSP::LoadComponent:150: (STUBBED) called size=0xC234, prog_mask=0x505300FF, data_mask=0x000700FF, buffer=0x006D5F2C
    [ 7.130937] Service.DSP core\hle\service\dsp_dsp.cpp:Service::DSP_DSP::RegisterInterruptEvents:241: Registered type=2, pipe=2, event_handle=0x0007801C
    [ 7.131610] Service.DSP core\hle\service\dsp_dsp.cpp:Service::DSP_DSP::GetSemaphoreEventHandle:167: (STUBBED) called
    [ 7.132042] Service.DSP core\hle\service\dsp_dsp.cpp:Service::DSP_DSP::SetSemaphoreMask:446: (STUBBED) called mask=0x00002000
    [ 7.132463] Audio.DSP audio_core\hle\pipe.cpp:DSP::HLE::PipeWrite:134: Application has requested initialization of DSP hardware
    [ 7.132779] Service.DSP core\hle\service\dsp_dsp.cpp:Service::DSP_DSP::SetSemaphore:264: (STUBBED) called
    [ 7.134376] Service.DSP core\hle\service\dsp_dsp.cpp:Service::DSP_DSP::SetSemaphore:264: (STUBBED) called
    [ 7.156871] Service.FS core\hle\service\fs\archive.cpp:Service::FS::File::HandleSyncRequest:172: (STUBBED) File command OpenLinkFile Path: [Binary: 000000000000000000000000]
    [ 7.193816] Service.GSP core\hle\service\gsp_gpu.cpp:Service::GSP::AcquireRight:692: called
    [ 7.195742] Service.GSP core\hle\service\gsp_gpu.cpp:Service::GSP::RegisterInterruptRelayQueue:386: called, flags=0x00000001
    [ 7.207026] HW.Memory core\memory.cpp:Memory::VirtualToPhysicalAddress:683: Unknown virtual address @ 0x00659010
    [ 7.226557] HW.Memory core\memory.cpp:Memory::VirtualToPhysicalAddress:683: Unknown virtual address @ 0x00659338
    [ 7.227871] HW.Memory core\memory.cpp:Memory::VirtualToPhysicalAddress:683: Unknown virtual address @ 0x00659678
    [ 7.230213] HW.Memory core\memory.cpp:Memory::VirtualToPhysicalAddress:683: Unknown virtual address @ 0x006CFF40
    [ 7.235400] Service.APT core\hle\service\apt\apt.cpp:Service::APT::AppletUtility:320: (STUBBED) called command=0x00000004, buffer1_size=0x00000001, buffer2_size=0x00000001, buffer1_addr=0x0FFFFF48, buffer2_addr=0x0FFFFF4C
    [ 7.254541] Service.LDR core\hle\service\ldr_ro\cro_helper.cpp:Service::LDR::CROHelper::ApplyStaticAnonymousSymbolToCRS:528: CRO “Title” exports 0 static anonymous symbols
    [ 7.256438] Service.LDR core\hle\service\ldr_ro\ldr_ro.cpp:Service::LDR::LoadCRO:464: CRO “Title” loaded at 0x00730000, fixed_end=0x0076D000
    [ 7.591768] Service.FS core\hle\service\fs\archive.cpp:Service::FS::File::HandleSyncRequest:172: (STUBBED) File command OpenLinkFile Path: [Binary: 000000000000000000000000]
    [ 15.390008] Service.LDR core\hle\service\ldr_ro\ldr_ro.cpp:Service::LDR::UnloadCRO:529: Unloading CRO “Title”
    [ 15.404332] Service.LDR core\hle\service\ldr_ro\cro_helper.cpp:Service::LDR::CROHelper::ApplyStaticAnonymousSymbolToCRS:528: CRO “Load” exports 0 static anonymous symbols
    [ 15.406593] Service.LDR core\hle\service\ldr_ro\ldr_ro.cpp:Service::LDR::LoadCRO:464: CRO “Load” loaded at 0x00730000, fixed_end=0x0075A000
    [ 18.613608] Service.LDR core\hle\service\ldr_ro\ldr_ro.cpp:Service::LDR::UnloadCRO:529: Unloading CRO “Load”
    [ 18.627107] Service.LDR core\hle\service\ldr_ro\cro_helper.cpp:Service::LDR::CROHelper::ApplyStaticAnonymousSymbolToCRS:528: CRO “FReal” exports 0 static anonymous symbols
    [ 18.628462] Service.LDR core\hle\service\ldr_ro\ldr_ro.cpp:Service::LDR::LoadCRO:464: CRO “FReal” loaded at 0x00730000, fixed_end=0x00732000
    [ 33.694851] Service.LDR core\hle\service\ldr_ro\ldr_ro.cpp:Service::LDR::UnloadCRO:529: Unloading CRO “FReal”
    [ 33.709774] Service.LDR core\hle\service\ldr_ro\cro_helper.cpp:Service::LDR::CROHelper::ApplyStaticAnonymousSymbolToCRS:528: CRO “Save” exports 0 static anonymous symbols
    [ 33.710788] Service.LDR core\hle\service\ldr_ro\ldr_ro.cpp:Service::LDR::LoadCRO:464: CRO “Save” loaded at 0x00730000, fixed_end=0x00756000
    [ 39.166942] Service.LDR core\hle\service\ldr_ro\ldr_ro.cpp:Service::LDR::UnloadCRO:529: Unloading CRO “Save”
    [ 39.180250] Service.LDR core\hle\service\ldr_ro\cro_helper.cpp:Service::LDR::CROHelper::ApplyStaticAnonymousSymbolToCRS:528: CRO “FReal” exports 0 static anonymous symbols
    [ 39.181480] Service.LDR core\hle\service\ldr_ro\ldr_ro.cpp:Service::LDR::LoadCRO:464: CRO “FReal” loaded at 0x00730000, fixed_end=0x00732000
    [ 45.257173] Service.LDR core\hle\service\ldr_ro\ldr_ro.cpp:Service::LDR::UnloadCRO:529: Unloading CRO “FReal”
    [ 45.309183] Service.LDR core\hle\service\ldr_ro\cro_helper.cpp:Service::LDR::CROHelper::ApplyStaticAnonymousSymbolToCRS:528: CRO “BNormal” exports 0 static anonymous symbols
    [ 45.310118] Service.LDR core\hle\service\ldr_ro\ldr_ro.cpp:Service::LDR::LoadCRO:464: CRO “BNormal” loaded at 0x00730000, fixed_end=0x00732000
    [ 45.386054] Service.HID core\hle\service\hid\hid.cpp:Service::HID::GetGyroscopeLowCalibrateParam:296: (STUBBED) called
    [ 45.409792] Service core\hle\service\service.cpp:Service::Interface::HandleSyncRequest:95: unknown / unimplemented function ‘GetStepHistory’: port=ptm:u, cmd_buff[1]=0x18, cmd_buff[2]=0x3B411400, cmd_buff[3]=0x7E, cmd_buff[4]=0x30C, cmd_buff[5]=0xFFFFE60
    [ 106.818845] Kernel.SVC core\hle\svc.cpp:SVC::CreateMemoryBlock:948: called addr=0x0801F000
    [ 106.819992] Service.MIC core\hle\service\mic_u.cpp:Service::MIC::MapSharedMem:60: called, size=0x1000, mem_handle=0x00140048
    [ 106.821240] Service.MIC core\hle\service\mic_u.cpp:Service::MIC::GetGain:192: (STUBBED) called
    [ 106.821933] Service.MIC core\hle\service\mic_u.cpp:Service::MIC::SetGain:177: (STUBBED) called, mic_gain=80
    [ 106.822198] Service.MIC core\hle\service\mic_u.cpp:Service::MIC::SetClamp:257: (STUBBED) called, clamp=1
    [ 106.822785] Service.MIC core\hle\service\mic_u.cpp:Service::MIC::StartSampling:103: (STUBBED) called, encoding=2, sample_rate=3, audio_buffer_offset=0, audio_buffer_size=2048, audio_buffer_loop=1
    [ 106.823386] Service.MIC core\hle\service\mic_u.cpp:Service::MIC::SetPower:207: (STUBBED) called, mic_power=1
    [ 189.011960] Service.MIC core\hle\service\mic_u.cpp:Service::MIC::SetPower:207: (STUBBED) called, mic_power=0
    [ 189.013305] Service.MIC core\hle\service\mic_u.cpp:Service::MIC::StopSampling:132: (STUBBED) called
    [ 189.014167] Service.MIC core\hle\service\mic_u.cpp:Service::MIC::SetGain:177: (STUBBED) called, mic_gain=0
    [ 189.014615] Service.MIC core\hle\service\mic_u.cpp:Service::MIC::IsSampling:147: (STUBBED) called
    [ 189.014867] Service.MIC core\hle\service\mic_u.cpp:Service::MIC::UnmapSharedMem:74: called
    [ 189.015320] Service.MIC core\hle\service\mic_u.cpp:Service::MIC::StopSampling:132: (STUBBED) called
    [ 189.024664] Service.LDR core\hle\service\ldr_ro\ldr_ro.cpp:Service::LDR::UnloadCRO:529: Unloading CRO “BNormal”
    [ 189.041812] Service.LDR core\hle\service\ldr_ro\cro_helper.cpp:Service::LDR::CROHelper::ApplyStaticAnonymousSymbolToCRS:528: CRO “FReal” exports 0 static anonymous symbols
    [ 189.043036] Service.LDR core\hle\service\ldr_ro\ldr_ro.cpp:Service::LDR::LoadCRO:464: CRO “FReal” loaded at 0x00730000, fixed_end=0x00732000
    [ 194.131842] Service.LDR core\hle\service\ldr_ro\ldr_ro.cpp:Service::LDR::UnloadCRO:529: Unloading CRO “FReal”
    [ 194.145802] Service.LDR core\hle\service\ldr_ro\ldr_ro.cpp:Service::LDR::LoadCRO:343: CRO original buffer is in invalid state
    [ 194.146127] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x000000A0
    [ 194.146187] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x000000C8
    [ 194.146432] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x000000CC
    [ 194.147014] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x000000A0
    [ 194.147152] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x000000C8
    [ 194.147839] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x000000CC
    [ 194.147969] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x000000A4
    [ 194.148140] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x000000C8
    [ 194.148409] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x000000CC
    [ 194.151136] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x00000000
    [ 194.151189] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x00000004
    [ 194.151777] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x00000008
    [ 194.151878] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x0000000C
    [ 194.152243] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x00000010
    [ 194.152716] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x00000014
    [ 194.152760] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x00000018
    [ 194.152986] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x0000001C
    [ 194.153205] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x00000020
    [ 194.153635] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x00000024
    [ 194.153684] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x00000028
    [ 194.153891] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x0000002C
    [ 194.154091] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x00000030
    [ 194.154279] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x00000034
    [ 194.154471] HW.Memory core\memory.cpp:Memory::Read:186: unmapped Read32 @ 0x00000038

    the invalid reads continued forever, each time incrementing address by 4

key events in the log:
at [33], successful attempt to switch from “FReal” to "Save"
at [39], switch back from “Save” to "FReal"
at [45], enter battle
at [106], inky piranha plant shows up in background
at [189], escape from battle, Service.MIC handles the disappearing of inky piranha plant, Service.LDR handles switch scene from “BNormal” to “FReal” (if I do not escape but instead kill inky piranha plant without ending the battle, the Service.MIC lines will show up in log as soon as it dies)
at [194] I attempted to save (attempted to switch from “FReal” to “Save”), but failed, followed by unstopping invalid reads (the 10th invalid read is at 0x00000000, subsequent reads at increment of 4)


#2

Post this bug to Github @ https://github.com/citra-emu/citra/issues , because this exact bug is not known. This seems like a APT service regression, based on https://github.com/citra-emu/citra/pull/2154 .


#3

@wwylele might wanna take a look at this one.

without looking too much into this, i’d guess the game is using CROs in a funky way thats not properly emulated in citra?


#4

and here we thought we’ve seen the last of CROs