Regressions again with sceIo

[realrunners]

Just detected this when testing. Has to be from a change made today.

21:39:116 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 308 (00000134)
21:39:116 HLE\sceIo.cpp:266 E[HLE]: sceIoRead ERROR: no file open
21:39:116 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 308 (00000134)
21:39:116 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 308 (00000134)
21:39:116 HLE\sceIo.cpp:791 E[HLE]: ERROR - sceIoPollAsync waiting for invalid id 308
21:39:116 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 308 (00000134)
21:39:116 HLE\sceIo.cpp:322 E[HLE]: sceIoLseek(308, 58320, 0) - ERROR: invalid file
21:39:116 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 308 (00000134)
21:39:116 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 308 (00000134)
21:39:116 HLE\sceIo.cpp:791 E[HLE]: ERROR - sceIoPollAsync waiting for invalid id 308
21:39:116 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 308 (00000134)
21:39:194 HLE\sceIo.cpp:266 E[HLE]: sceIoRead ERROR: no file open
21:39:194 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 308 (00000134)
21:39:194 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 308 (00000134)
21:39:210 HLE\sceIo.cpp:791 E[HLE]: ERROR - sceIoPollAsync waiting for invalid id 308
21:39:210 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 308 (00000134)
21:39:210 HLE\sceIo.cpp:322 E[HLE]: sceIoLseek(308, 58320, 0) - ERROR: invalid file
21:39:210 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 308 (00000134)
21:39:210 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 308 (00000134)
21:39:210 HLE\sceIo.cpp:791 E[HLE]: ERROR - sceIoPollAsync waiting for invalid id 308
21:39:210 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 308 (00000134)

[hrydgard]

Thanks, I'll look into it. Always mention what game you tested though!

[realrunners]

The game is Brandish. But the error is also present in f.e. Zwei! with a different value:

39:05:475 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 325 (00000145)
39:05:475 HLE\sceIo.cpp:791 E[HLE]: ERROR - sceIoPollAsync waiting for invalid id 325
39:05:475 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 325 (00000145)
39:05:475 HLE\sceIo.cpp:791 E[HLE]: ERROR - sceIoPollAsync waiting for invalid id 325
39:05:475 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 325 (00000145)
39:05:475 HLE\sceIo.cpp:791 E[HLE]: ERROR - sceIoPollAsync waiting for invalid id 325
39:05:678 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 325 (00000145)
39:05:678 HLE\sceIo.cpp:791 E[HLE]: ERROR - sceIoPollAsync waiting for invalid id 325
39:05:678 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 325 (00000145)
39:05:678 HLE\sceIo.cpp:791 E[HLE]: ERROR - sceIoPollAsync waiting for invalid id 325
39:05:678 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 325 (00000145)
39:05:678 HLE\sceIo.cpp:791 E[HLE]: ERROR - sceIoPollAsync waiting for invalid id 325
39:05:678 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 325 (00000145)
39:05:678 HLE\sceIo.cpp:791 E[HLE]: ERROR - sceIoPollAsync waiting for invalid id 325
39:05:678 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 325 (00000145)
39:05:678 HLE\sceIo.cpp:791 E[HLE]: ERROR - sceIoPollAsync waiting for invalid id 325
39:05:678 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 325 (00000145)
39:05:678 HLE\sceIo.cpp:791 E[HLE]: ERROR - sceIoPollAsync waiting for invalid id 325

[B1ackDaemon]

Hmm...i'm also noticed, that Mortal Kombat: Unchained was broken between fefc229 and 86a2760
Logs from debug versions: rghost.net/42120803

[hrydgard]

Most likely another scheduling problem where the threads run in the wrong order. @unknownbrackets will have to take a look :)

[unknownbrackets]

Darn. I don't have any of these three games. Some really interesting stuff is happening in Mortal Kombat, though.

Can you git bisect possibly to find which commit exactly, possibly?

Also, in both it's ending up with a bad sema (a bad name), which is really interesting. I'd like to know why.

This is also super interesting:

stdout: SCREAM: Lib wave didn't take all of our last submit (took 0 of 2048)!
stdout:         calling sceWaveAudioSetSample and hoping for the best.

Anyway, I think I finally found the difference. In the broken one it is never returning to user_main after this:

Left callback 295 - MKMSCallback
Context saved (return from callback): 276 - user_main - pc: 08a2775c
Context loaded (return from callback): 278 - callbacks - pc: 089ecddc

So then it goes into an idle loop. Obviously user_main is never becoming runnable again which is wrong. I'm guessing it has isProcessingCallbacks stuck, which means my fix for ff7e1d7 probably broke one thing and fixed another.

If you go back to 9cd47e2 does it work?

-[Unknown]

[B1ackDaemon]

Checked commits 9cd47e2 and ff7e1d7 - game MK: Unchained works on both of them. (Release)

a bit offtopic: Btw, would be good to have some hidden/private section on forum if devs have no stuff for testing. ;P Or i'll go to IRC, and we talk about it. ;D

[hrydgard]

I could make a hidden dev forum but most dev discussions are fine to have right here in public on the github issue tracker. If you feel otherwise, yeah, there's always IRC :P

[unknownbrackets]

@B1ackDaemon: yes, please come to IRC, could probably narrow this down faster.

So, that's interesting. Must be a later commit... hmm.

-[Unknown]

[unknownbrackets]

Does it work in 000884f? Sorry.

-[Unknown]

[unknownbrackets]

Okay, I think I have an idea at least. Does it work on the tip of this branch?

https://github.com/unknownbrackets/ppsspp/tree/scheduling2

Specifically, does a1a4a02 fix it?

@Darth1701 sorry for hijacking a bit, would like to know if this fixes it for you also - or else, more of the logs would help.

-[Unknown]

[realrunners]

@unknownbrackets Don't worry, that is quite OK. :)

I still have the error in Zwei!:

59:05:625 FileSystems\ISOFileSystem.cpp:303 I[FileSys]: Got a raw sector open: /sce_lbn0567b0_size0x1490, sector 000067b0, size 00001490
59:05:625 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 325 (00000145)
59:05:625 HLE\sceIo.cpp:329 E[HLE]: sceIoLseek(325, 48, 0) - ERROR: invalid file
59:05:625 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 325 (00000145)
59:05:625 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 325 (00000145)
59:05:625 HLE\sceIo.cpp:798 E[HLE]: ERROR - sceIoPollAsync waiting for invalid id 325
59:05:625 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 325 (00000145)
59:05:625 HLE\sceIo.cpp:798 E[HLE]: ERROR - sceIoPollAsync waiting for invalid id 325
59:05:625 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 325 (00000145)
59:05:625 HLE\sceIo.cpp:798 E[HLE]: ERROR - sceIoPollAsync waiting for invalid id 325
59:05:625 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 325 (00000145)
59:05:625 HLE\sceIo.cpp:798 E[HLE]: ERROR - sceIoPollAsync waiting for invalid id 325
59:05:625 c:\ppsspp\ppsspp\core\hle\sceKernel.h:348 E[HLE]: Kernel: Bad object handle 325 (00000145)
59:05:625 HLE\sceIo.cpp:798 E[HLE]: ERROR - sceIoPollAsync waiting for invalid id 325

althought it doesn't hurt the game itself. I could be sound related.

In Brandish the error is gone.

[unknownbrackets]

Oh, I fixed an error recently with another game that was like that. I think that's a separate bug, probably.

So sounds like Brandish is fixed - hurray. I'll send a pull then.

-[Unknown]