Daemon icon indicating copy to clipboard operation
Daemon copied to clipboard

The nexe loading log could be more useful

Open illwieckz opened this issue 3 years ago • 9 comments

Here is what I get when I try to load an exe on arm:

$ ./daemonded -set vm.sgame.type 1 +devmap plat23
Using loader args:  nacl_helper_bootstrap nacl_loader --r_debug=0xXXXXXXXXXXXXXXXX --reserved_at_zero=0xXXXXXXXXXXXXXXXX -v -B irt_core-arm.nexe -e -i 100:25 -- sgame-arm.nexe 100 
Warn: IPC: Socket closed by remote end

The message is meaningless.

If I run the command by hand, this is what I get:

$ ./nacl_helper_bootstrap nacl_loader --r_debug=0xXXXXXXXXXXXXXXXX --reserved_at_zero=0xXXXXXXXXXXXXXXXX -v -B irt_core-arm.nexe -e -i 100:25 -- sgame-arm.nexe 100
sel_ldr argument list:
nacl_loader --r_debug=0x0000000040002000 --reserved_at_zero=0x0000000040002000 -v -B irt_core-arm.nexe -e -i 100:25 -- sgame-arm.nexe 100
[471888,4149006400:03:28:04.970230] Error while loading "sgame-arm.nexe": CPU model is not supported
[471888,4149006400:03:28:04.971045] NaClPerfCounterInterval(SelMain __start__:SnapshotBlob): 1153 microsecs
[471888,4149006400:03:28:04.971180] NACL: Application output follows
[471888,4149006400:03:28:04.971212] NaClAppStartModule: module not loaded
Dumping vmmap.
In PrintVmmap
Done.

This is far more useful.

illwieckz avatar Nov 09 '22 02:11 illwieckz

I guess it must be some kind of flushing problem. Either the process exits without flushing or we kill it before it can write and flush its output.

slipher avatar Nov 09 '22 20:11 slipher

Wait a minute, did you actually open the log file? You just show the daemonded output in the OP but you're supposed to look in <homepath>/cgame.nacl_loader.log to see this stuff.

slipher avatar Nov 09 '22 20:11 slipher

I think we want to put this not in the cgame.nacl_loader.log since I don't think this is enabled by default and print these types of errors to the console because that's where people look for errors?

DolceTriade avatar Nov 10 '22 03:11 DolceTriade

I think we want to put this not in the cgame.nacl_loader.log since I don't think this is enabled by default and print these types of errors to the console because that's where people look for errors?

No, because that would be too much spam. On my machine it prints 17 lines for a normal startup at the default (lowest other than muted) log level.

slipher avatar Nov 10 '22 03:11 slipher

It obviously doesn't always have to print to console, but maybe in the error case it can. This means that we have to always log to file and maybe read it back (or the last 10 lines) or something in the event of an error.

DolceTriade avatar Nov 10 '22 03:11 DolceTriade

Wait a minute, did you actually open the log file? You just show the daemonded output in the OP but you're supposed to look in <homepath>/cgame.nacl_loader.log to see this stuff.

I didn't knew this file exists, I never used it and I never seen someone using it to troubleshoot IPC: Socket closed by remote end errors. I always helped people reporting IPC: Socket closed by remote end errors by blindly iterating some checklist (like verifying if NX bit is enabled in BIOS) without reading this file at all.

When such error happens there is even no message saying there is more information to be found in that file.

Can we dump this log file content in case of error?

illwieckz avatar Nov 10 '22 11:11 illwieckz

I have asked people to send me the loader log to debug stuff, but the truth is it has rarely been useful. For example with the Slackware bug where the kernel configuration setting blocked the executable from loading at a low address, the process never even started so it couldn't log anything.

slipher avatar Nov 10 '22 14:11 slipher

Well, even with my current case the log doesn't help me that much, but I'm just super-surprised we have more logs.

At least for me Error while loading "sgame-arm.nexe": CPU model is not supported confirms me it actually tries to load the right file and that it may be failing at detecting something about the CPU.

illwieckz avatar Nov 10 '22 15:11 illwieckz

Is there anything more we could ask of this log?

slipher avatar Oct 23 '24 19:10 slipher