mizu icon indicating copy to clipboard operation
mizu copied to clipboard

Appears to not work on a raspberry pi 4

Open buddyjojo opened this issue 1 year ago • 21 comments

I know this project is very WIP and the pi is definitely not the best at doing something like this but for fun I tried to compile and run it on it but it just doesn't do anything when I try to hlaunch anything (like 2048) and I have no clue how to debug this.

I have applied what I assume is all the patches required to the pi's kernel (here's the fork I applied the patches to) and the mizu service appears to be running fine.

I'm not sure if I'm doing anything wrong as I can't find much on how to use this thing and again I also have no clue where to find any logs that can help.

buddyjojo avatar Aug 19 '22 01:08 buddyjojo

The log of your last run will be at ~/.local/share/mizu/log/mizu_log.txt if mizu is really running (I’d recommend stopping mizu before checking this, just to make sure everything’s flushed).

I’m pretty sure that what’s happening is that your Vulkan api is being rejected, I’m pretty sure the Pi is missing some extensions. You could try to comment out some of these checks in mizu and rebuild to see what happens. Let me know if you actually get anything displayed.

kentjhall avatar Aug 19 '22 16:08 kentjhall

So Ive tired commenting out a few checks (the ones that throw VK_ERROR_INCOMPATIBLE_DRIVER, VK_ERROR_FEATURE_NOT_PRESENT and VK_ERROR_EXTENSION_NOT_PRESENT) but that didn't do much.

I'm not sure if I missed any other checks (I only edited vulkan_device.cpp and vulkan_instance.cpp).

Ive also tried updating to the latest mesa which should be "Vulkan 1.2 Compliant" on the pi

Now this is all that the logs say:

[   0.000286] Common.Filesystem <Debug> common/fs/fs.cpp:CreateDir:181: Filesystem object at path=/home/jjaut/.config/mizu exists and is a directory
[   0.185694] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/nand/system/Contents/registered
[   0.185756] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/nand/system/Contents/registered
[   0.185868] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/nand/user/Contents/registered
[   0.185915] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/nand/user/Contents/registered
[   0.186069] Common.Filesystem <Debug> common/fs/fs.cpp:RemoveDirRecursively:279: Filesystem object at path=/home/jjaut/.local/share/mizu/nand/temp does not exist
[   0.186168] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/sdmc/Nintendo/Contents/registered
[   0.186214] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/sdmc/Nintendo/Contents/registered
[   0.186388] Common.Filesystem <Error> common/fs/file.cpp:Open:263: Failed to open the file at path=/home/jjaut/.local/share/mizu/nand/system/save/8000000000000010/su/avators/profiles.dat, ec_message=No such file or directory

but weirdly if I try loading first the homebrew then a retail rom that apparently is "a different type than its extension" for some reason it logs more:

 [   0.000289] Common.Filesystem <Debug> common/fs/fs.cpp:CreateDir:181: Filesystem object at path=/home/jjaut/.config/mizu exists and is a directory
[   0.186182] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/nand/system/Contents/registered
[   0.186245] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/nand/system/Contents/registered
[   0.186359] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/nand/user/Contents/registered
[   0.186406] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/nand/user/Contents/registered
[   0.186559] Common.Filesystem <Debug> common/fs/fs.cpp:RemoveDirRecursively:279: Filesystem object at path=/home/jjaut/.local/share/mizu/nand/temp does not exist
[   0.186660] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/sdmc/Nintendo/Contents/registered
[   0.186706] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/sdmc/Nintendo/Contents/registered
[   0.186883] Common.Filesystem <Error> common/fs/file.cpp:Open:263: Failed to open the file at path=/home/jjaut/.local/share/mizu/nand/system/save/8000000000000010/su/avators/profiles.dat, ec_message=No such file or directory
[   0.186895] Service.ACC <Warning> core/hle/service/acc/profile_manager.cpp:ParseUserSaveFile:339: Failed to load profile data from save data... Generating new user 'mizu' with random UUID.
[   0.212621] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'TimeZoneBinary' (0x010000000000080E).
[   0.212888] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.213557] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'TimeZoneBinary' (0x010000000000080E).
[   0.213672] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.548830] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontStandard' (0x0100000000000811).
[   0.552270] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.556286] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontChineseSimple' (0x0100000000000814).
[   0.562861] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.566909] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontChineseSimple' (0x0100000000000814).
[   0.572891] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.577914] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontChineseTraditional' (0x0100000000000813).
[   0.580408] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.584112] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontKorean' (0x0100000000000812).
[   0.586438] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.590054] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontNintendoExtension' (0x0100000000000810).
[   0.590328] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.590499] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontNintendoExtension' (0x0100000000000810).
[   0.590684] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   4.159065] Common.Filesystem <Debug> common/fs/fs.cpp:FileOpen:159: Successfully opened the file at path=/home/jjaut/2048.nro with mode=1, type=0, flag=1
[   4.159259] Loader <Debug> core/loader/loader.cpp:GetLoader:274: Loading file 2048.nro as NRO...
[   5.415120] Common.Filesystem <Debug> common/fs/fs.cpp:FileOpen:159: Successfully opened the file at path=/home/jjaut/Puyo Puyo Tetris.nsp with mode=1, type=0, flag=1
[   5.415732] Loader <Warning> core/loader/loader.cpp:GetLoader:268: File Puyo Puyo Tetris.nsp has a different type than its extension.
[   5.415750] Loader <Debug> core/loader/loader.cpp:GetLoader:274: Loading file Puyo Puyo Tetris.nsp as NSP...
[   5.419896] Core <Critical> core/loader/loader.cpp:RunForever:442: Failed to load ROM at '/home/jjaut/Puyo Puyo Tetris.nsp' (Error 14)!

But ether way it appears to just "get stuck" when loading a rom.

buddyjojo avatar Aug 19 '22 20:08 buddyjojo

Homebrew should work, but you have the prod.keys file for Puyo right? It's required the same as for yuzu.

kentjhall avatar Aug 19 '22 20:08 kentjhall

Is this the entirety of your log? If you could, please try running ./mizu, then launching 2048.nro, then kill the mizu task, and send me the whole log. And make sure mizu isn't already running as a service or anything.

kentjhall avatar Aug 19 '22 20:08 kentjhall

Homebrew should work, but you have the prod.keys file for Puyo right? It's required the same as for yuzu.

I wasn't sure if that was required or not but I was also not sure where to put it so I didn't I'll try to put them in then.

Is this the entirety of your log? If you could, please try running ./mizu, then launching 2048.nro, then kill the mizu task, and send me the whole log. And make sure mizu isn't already running as a service or anything.

Yep that was the entire log.

Doing the ./mizu thing it just outputs pretty much the same thing but at least it logs more without trying to first cause an error.

[   0.001333] Common.Filesystem <Debug> common/fs/fs.cpp:CreateDir:181: Filesystem object at path=/home/jjaut/.config/mizu exists and is a directory
[   0.187956] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/nand/system/Contents/registered
[   0.188019] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/nand/system/Contents/registered
[   0.188134] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/nand/user/Contents/registered
[   0.188181] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/nand/user/Contents/registered
[   0.188345] Common.Filesystem <Debug> common/fs/fs.cpp:RemoveDirRecursively:279: Filesystem object at path=/home/jjaut/.local/share/mizu/nand/temp does not exist
[   0.188451] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/sdmc/Nintendo/Contents/registered
[   0.188498] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/sdmc/Nintendo/Contents/registered
[   0.188727] Common.Filesystem <Error> common/fs/file.cpp:Open:263: Failed to open the file at path=/home/jjaut/.local/share/mizu/nand/system/save/8000000000000010/su/avators/profiles.dat, ec_message=No such file or directory
[   0.188739] Service.ACC <Warning> core/hle/service/acc/profile_manager.cpp:ParseUserSaveFile:339: Failed to load profile data from save data... Generating new user 'mizu' with random UUID.
[   0.196738] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'TimeZoneBinary' (0x010000000000080E).
[   0.197046] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.197714] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'TimeZoneBinary' (0x010000000000080E).
[   0.197834] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.548485] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontStandard' (0x0100000000000811).
[   0.551911] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.555988] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontChineseSimple' (0x0100000000000814).
[   0.562732] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.566744] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontChineseSimple' (0x0100000000000814).
[   0.572898] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.577893] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontChineseTraditional' (0x0100000000000813).
[   0.580397] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.584092] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontKorean' (0x0100000000000812).
[   0.586514] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.590187] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontNintendoExtension' (0x0100000000000810).
[   0.590463] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.590637] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontNintendoExtension' (0x0100000000000810).
[   0.590824] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[  17.883712] Common.Filesystem <Debug> common/fs/fs.cpp:FileOpen:159: Successfully opened the file at path=/home/jjaut/2048.nro with mode=1, type=0, flag=1
[  17.883901] Loader <Debug> core/loader/loader.cpp:GetLoader:274: Loading file 2048.nro as NRO...

Again this is all that is in the log file.

buddyjojo avatar Aug 19 '22 20:08 buddyjojo

Huh so putting in the key and trying to launch Puyo again it actually logs more. Still does not appear to do anything though. It looks like it might be slowly doing stuff but I'm not sure how long I need to wait or if its still not working. Though i see little to no disk activity and not much cpu activity

[   0.000264] Common.Filesystem <Debug> common/fs/fs.cpp:CreateDir:181: Filesystem object at path=/home/jjaut/.config/mizu exists and is a directory
[   0.188108] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/nand/system/Contents/registered
[   0.188170] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/nand/system/Contents/registered
[   0.188284] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/nand/user/Contents/registered
[   0.188334] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/nand/user/Contents/registered
[   0.188487] Common.Filesystem <Debug> common/fs/fs.cpp:RemoveDirRecursively:279: Filesystem object at path=/home/jjaut/.local/share/mizu/nand/temp does not exist
[   0.188634] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/sdmc/Nintendo/Contents/registered
[   0.188681] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/sdmc/Nintendo/Contents/registered
[   0.188853] Common.Filesystem <Error> common/fs/file.cpp:Open:263: Failed to open the file at path=/home/jjaut/.local/share/mizu/nand/system/save/8000000000000010/su/avators/profiles.dat, ec_message=No such file or directory
[   0.188865] Service.ACC <Warning> core/hle/service/acc/profile_manager.cpp:ParseUserSaveFile:339: Failed to load profile data from save data... Generating new user 'mizu' with random UUID.
[   0.217433] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'TimeZoneBinary' (0x010000000000080E).
[   0.217696] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.218366] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'TimeZoneBinary' (0x010000000000080E).
[   0.218477] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.548101] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontStandard' (0x0100000000000811).
[   0.551446] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.555423] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontChineseSimple' (0x0100000000000814).
[   0.561898] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.565865] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontChineseSimple' (0x0100000000000814).
[   0.571926] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.576907] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontChineseTraditional' (0x0100000000000813).
[   0.579438] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.583142] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontKorean' (0x0100000000000812).
[   0.585451] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.589061] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontNintendoExtension' (0x0100000000000810).
[   0.589338] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   0.589506] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:78: Synthesizing system archive 'FontNintendoExtension' (0x0100000000000810).
[   0.589693] Service.FS <Info> core/file_sys/system_archive/system_archive.cpp:SynthesizeSystemArchive:93:     - System archive generation successful!
[   2.801530] Common.Filesystem <Debug> common/fs/fs.cpp:FileOpen:159: Successfully opened the file at path=/home/jjaut/Puyo Puyo Tetris.nsp with mode=1, type=0, flag=1
[   2.803249] Loader <Debug> core/loader/loader.cpp:GetLoader:274: Loading file Puyo Puyo Tetris.nsp as NSP...
[   2.804241] Loader <Debug> core/file_sys/patch_manager.cpp:PatchRomFS:421: Patching RomFS for title_id=010073C001D5E000, type=03
[   2.811670] Loader <Info> core/file_sys/patch_manager.cpp:PatchExeFS:131: Patching ExeFS for title_id=010073C001D5E000
[   2.812046] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/load/010073C001D5E000
[   2.812117] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/load/010073C001D5E000
[   2.812248] Service.FS <Debug> core/file_sys/program_metadata.cpp:Print:122: Magic:                  META
[   2.812263] Service.FS <Debug> core/file_sys/program_metadata.cpp:Print:123: Main thread priority:   0x2C
[   2.812269] Service.FS <Debug> core/file_sys/program_metadata.cpp:Print:124: Main thread core:       0
[   2.812276] Service.FS <Debug> core/file_sys/program_metadata.cpp:Print:125: Main thread stack size: 0x100000 bytes
[   2.812281] Service.FS <Debug> core/file_sys/program_metadata.cpp:Print:126: Process category:       0
[   2.812287] Service.FS <Debug> core/file_sys/program_metadata.cpp:Print:127: Flags:                  0x03
[   2.812293] Service.FS <Debug> core/file_sys/program_metadata.cpp:Print:128:  > 64-bit instructions: YES
[   2.812299] Service.FS <Debug> core/file_sys/program_metadata.cpp:Print:147:  > Address space:       64-bit (36-bit address space)

[   2.812305] Service.FS <Debug> core/file_sys/program_metadata.cpp:Print:150: Magic:                  ACID
[   2.812311] Service.FS <Debug> core/file_sys/program_metadata.cpp:Print:151: Flags:                  0x03
[   2.812316] Service.FS <Debug> core/file_sys/program_metadata.cpp:Print:152:  > Is Retail:           YES
[   2.812324] Service.FS <Debug> core/file_sys/program_metadata.cpp:Print:153: Title ID Min:           0x0100000000010000
[   2.812330] Service.FS <Debug> core/file_sys/program_metadata.cpp:Print:154: Title ID Max:           0x01FFFFFFFFFFFFFF
[   2.812336] Service.FS <Debug> core/file_sys/program_metadata.cpp:Print:157: Filesystem Access:      0xB6CD85D92214921D

[   2.812342] Service.FS <Debug> core/file_sys/program_metadata.cpp:Print:160: Magic:                  ACI0
[   2.812348] Service.FS <Debug> core/file_sys/program_metadata.cpp:Print:161: Title ID:               0x010073C001D5E000
[   2.812354] Service.FS <Debug> core/file_sys/program_metadata.cpp:Print:162: Filesystem Access:      0x0000000000000000

[   2.812834] Loader <Info> core/file_sys/patch_manager.cpp:HasNSOPatch:300: Querying NSO patch existence for build_id=EE74943B8B0768646B0DC278055D77EB09908393
[   2.813019] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/load/010073C001D5E000
[   2.813061] Loader <Debug> core/loader/deconstructed_rom_directory.cpp:Load:147: loaded module rtld at index 0
[   3.346894] Loader <Info> core/file_sys/patch_manager.cpp:HasNSOPatch:300: Querying NSO patch existence for build_id=3BD4235A072D5444A5EBFD6CFFBBB545
[   3.347145] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/load/010073C001D5E000
[   3.347191] Loader <Debug> core/loader/deconstructed_rom_directory.cpp:Load:147: loaded module main at index 1
[   3.363521] Loader <Info> core/file_sys/patch_manager.cpp:HasNSOPatch:300: Querying NSO patch existence for build_id=6C6ADB0C365E618A80D0436E2AC54DAFD85C890C
[   3.363773] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/load/010073C001D5E000
[   3.363820] Loader <Debug> core/loader/deconstructed_rom_directory.cpp:Load:147: loaded module subsdk0 at index 2
[   3.364943] Loader <Info> core/file_sys/patch_manager.cpp:HasNSOPatch:300: Querying NSO patch existence for build_id=528E3B2F27F863716F2311600708C242DB205C94
[   3.365109] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/load/010073C001D5E000
[   3.365140] Loader <Debug> core/loader/deconstructed_rom_directory.cpp:Load:147: loaded module subsdk1 at index 3
[   3.367721] Loader <Info> core/file_sys/patch_manager.cpp:HasNSOPatch:300: Querying NSO patch existence for build_id=72446C8344974FBEF04EA3DDFA8E3C74EB2E2465
[   3.367932] Common.Filesystem <Debug> common/fs/fs.cpp:IterateDirEntries:461: Successfully visited all the directory entries of path=/home/jjaut/.local/share/mizu/load/010073C001D5E000
[   3.367 ...it cuts of here.

buddyjojo avatar Aug 19 '22 21:08 buddyjojo

That's odd, it appears in both of your cases that the Horizon task is never communicating with mizu... you can check if, in the 2048 test (let's stick to the simple case for now), the process is ever actually launched by the loader with:

ps -ef | grep 2048

I'll probably try your patch of Linux for the Pi this weekend on my own and see what I can figure out. Hard to debug this way :/

kentjhall avatar Aug 19 '22 21:08 kentjhall

That's odd, it appears in both of your cases that the Horizon task is never communicating with mizu... you can check if, in the 2048 test (let's stick to the simple case for now), the process is ever actually launched by the loader with:

ps -ef | grep 2048

That outputs:

jjaut@raspberrypi:~/mizu $ ps -ef | grep 2048
jjaut      12489   12374  0 22:48 ?        00:00:00 [2048] <defunct>
jjaut      12491    1471  0 22:48 pts/0    00:00:00 grep --color=auto 2048

buddyjojo avatar Aug 19 '22 21:08 buddyjojo

This means it was started and it just poops itself. Here's my methodology for system call tracing if you really wanna go deep with this:

sudo su
cd /sys/kernel/debug/tracing
grep hsys available_filter_functions > set_ftrace_filter
echo function > current_tracer
echo 1 > tracing_on
cat trace_pipe

This will dump every Horizon system call made. Then in a separate shell, you can run the 2048 test and we can get a rough idea of what that task is actually doing before it crashes / exits.

kentjhall avatar Aug 19 '22 21:08 kentjhall

Note that the above method requires tracing to be abled in your kernel config, but this is usually the case by default.

kentjhall avatar Aug 19 '22 21:08 kentjhall

Odd, trace_pipe stays completely empty.

And yes tracing is enabled in the kernel.

buddyjojo avatar Aug 19 '22 22:08 buddyjojo

That doesn't really make sense... anything interesting in dmesg when running the test?

kentjhall avatar Aug 19 '22 22:08 kentjhall

It sounds to me like the task is just getting killed before it can do anything.

kentjhall avatar Aug 19 '22 22:08 kentjhall

That doesn't really make sense... anything interesting in dmesg when running the test?

The only interesting thing I see is this

[ 2150.489410] v3d fec00000.v3d: MMU error from client L2T (0) at 0x5869700, pte invalid
[ 8575.511407] horizon get_thread_priority: stubbed
[ 8604.631232] horizon get_thread_priority: stubbed
[ 8712.716009] horizon get_thread_priority: stubbed
[ 8715.345003] horizon get_thread_priority: stubbed
[ 8873.401221] horizon get_thread_priority: stubbed
[ 9208.663965] horizon get_thread_priority: stubbed
[ 9248.968099] horizon get_thread_priority: stubbed
[ 9448.214050] horizon get_thread_priority: stubbed
[ 9634.246503] horizon get_thread_priority: stubbed
[ 9707.629125] horizon get_thread_priority: stubbed

Other then that nothing else in dmesg other then the regular boot stuff.

buddyjojo avatar Aug 19 '22 22:08 buddyjojo

That means horizon system calls were executed, which means something is wrong with how you traced. I just looked back and it appears I did a typo, echo 1 > tracing on had a space instead of underscore; it should be echo 1 > tracing_on. Try fixing that, and you should be able to cat out those files we wrote to to be sure everything is set correctly. Then try running the test again

kentjhall avatar Aug 19 '22 22:08 kentjhall

Yeah I noticed that typo too so that wasn't it.

here's the cat output of all the files:

root@raspberrypi:/sys/kernel/debug/tracing# cat set_ftrace_filter
__arm64_hsys_ni_syscall
__arm64_hsys_get_system_tick
__arm64_hsys_exit_process
__arm64_hsys_exit_thread
__arm64_hsys_unmap_physical_memory
__arm64_hsys_map_physical_memory
__arm64_hsys_get_thread_id
__arm64_hsys_signal_process_wide_key
__arm64_hsys_wait_process_wide_key_atomic
__arm64_hsys_arbitrate_unlock
__arm64_hsys_arbitrate_lock
__arm64_hsys_close_handle
__arm64_hsys_map_shared_memory
__arm64_hsys_reset_signal
__arm64_hsys_sleep_thread
__arm64_hsys_unmap_memory
__arm64_hsys_map_memory
__arm64_hsys_set_memory_attribute
__arm64_hsys_set_heap_size
__arm64_hsys_unmap_shared_memory
__arm64_hsys_clear_event
__arm64_hsys_connect_to_named_port
__arm64_hsys_create_transfer_memory
__arm64_hsys_start_thread
__arm64_hsys_output_debug_string
__arm64_hsys_get_info
__arm64_hsys_wait_synchronization
__arm64_hsys_create_thread
__arm64_hsys_send_sync_request
__arm64_hsys_query_memory
hsys_ni_syscall
__arm64_hsys_get_thread_priority
__arm64_hsys_set_thread_core_mask
__arm64_hsys_break
root@raspberrypi:/sys/kernel/debug/tracing# cat current_tracer
function
root@raspberrypi:/sys/kernel/debug/tracing# cat tracing_on
1
root@raspberrypi:/sys/kernel/debug/tracing# cat trace_pipe
^C
root@raspberrypi:/sys/kernel/debug/tracing# 

Again nothing in trace_pipe.

buddyjojo avatar Aug 19 '22 22:08 buddyjojo

Sorry but just to be clear, you're doing cat trace_pipe while running the test concurrently in another shell, right? If you do sudo dmesg -w as well in another shell, you should see definitely see the cat trace_pipe session respond whenever dmesg shows "horizon get_thread_priority: stubbed", since that print is coming from the __arm64_hsys_get_thread_priority function that you are tracing.

kentjhall avatar Aug 19 '22 23:08 kentjhall

Oddly this time I'm not getting that "horizon get_thread_priority: stubbed" when running the cat command. And yes I'm running hlaunch and cat trace_pipe in two different terminal windows.

buddyjojo avatar Aug 19 '22 23:08 buddyjojo

I think those messages may have been from when you tried to run Puyo. Super bizarre that it would get somewhere when 2048 executes nothing, though... I'll have to try this out when I get a sec to mess with my Pi. Thanks for trying this out though! Keep me posted if you try anything else

kentjhall avatar Aug 20 '22 07:08 kentjhall

Not sure if it would be better if you compile the kernel yourself to rule out kernel problems but I do have a precompiled kernel package here if you'd want to save some time.

buddyjojo avatar Aug 20 '22 08:08 buddyjojo

I think those messages may have been from when you tried to run Puyo.

Ok so yep oddly that is the case. here's the output of trace_pipe with puyo.

 Puyo Puyo™ Te-1316    [000] ...1.   300.411890: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.411900: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.411902: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.411903: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.845696: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.845704: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.845705: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.846259: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.846262: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.846264: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.846309: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.846311: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.846312: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.846359: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.846361: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.846362: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.846386: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.846388: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.846389: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.847971: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.847976: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.847978: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.910179: __arm64_hsys_get_info <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.910186: __arm64_hsys_get_info <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.910226: __arm64_hsys_query_memory <-invoke_syscall
 Puyo Puyo™ Te-1316    [000] ...1.   300.910234: __arm64_hsys_get_thread_priority <-invoke_syscall

Though not sure how useful this is.

buddyjojo avatar Aug 20 '22 22:08 buddyjojo