Logging hook #225
Logging hook #225
Conversation
|
Example of how this can be used: static void kscrashRedirectedLogging(const char* const level,
const char* const file,
const int line,
const char* const function,
const char* const fmt, va_list args)
{
QtMsgType messageType = QtDebugMsg;
if (level) {
switch (level[0]) {
case 'E':
messageType = QtCriticalMsg;
break;
case 'W':
messageType = QtWarningMsg;
break;
case 'F':
messageType = QtFatalMsg;
break;
case 'I':
messageType = QtInfoMsg;
break;
case 'D':
case 'T':
messageType = QtDebugMsg;
break;
}
}
const QLoggingCategory &kscrash = lcKSCrashInternal();
if (!kscrash.isEnabled(messageType))
return;
QMessageLogContext context(file, line, function, kscrash.categoryName());
qt_message_output(messageType, context, QString::vasprintf(fmt, args));
} |
|
While this works, it's also very dangerous in the example code given, because everything, including async-safe code in the actual crash handlers, will call into this hook, and potentially hang the app when QT (or whatever higher level function you call) does a memory allocation. The logging mechanism for a crash handler must ALWAYS be async-safe, which means that you're restricted to open(), close(), and write() and such. The write to stdout should definitely be optional. And in fact it was once a long time ago and I think it went this way while I was debugging something (because I needed it to log to both file and stdout). It should ideally be configurable. I'll see if I can get some time together over the weekend... |
|
You're right, the code i pasted does indeed malloc, e.g. when formatting the message: Does KSCrash set some atomic state when detecting a crash, which can be read out by e.g Don't worry about the stdout-API, I can cook up a patch for that. Thanks for your feedback! |
torarnv
force-pushed
the
logging-hook
branch
2 times, most recently
from
f7e1c00
to
f2a7450
Compare
| * output will be disabled unless the handler has its own | ||
| * mechanism for dealing with those. | ||
| * | ||
| * WARNING: Only call async-safe functions from this function! |
There was a problem hiding this comment.
Added a warning here, like for other callbacks that happen after a potential crash
| * | ||
| * By default stdout logging is enabled. | ||
| */ | ||
| void kslog_setLogToStdout(bool enabled); |
There was a problem hiding this comment.
Something like this? I've kept the current behavior of logging to stdout by default.
One related issue is that kslog_setLogFilename is called unconditionally from kscrash_install, so from a public API pov it is a bit confusing. You have to call it twice, before and after installing KSCrash, and you'll miss any logging that happens during the install (it will end up in ConsoleLog.txt). Perhaps I'm misunderstanding the use of kslog_setLogFilename?
There was a problem hiding this comment.
hmm that definitely shouldn't have happened. KSLogger was originally a standalone logging system that I used in a few projects, but eventually settled permanently in KSCrash, since it's really the only thing that needs such a slow level logging mechanism. So at first it had a "default" file descriptor (stdout) that it wrote to, and then if you called kslog_setLogFilename, it would replace that descriptor (so that if you never called it, you'd still get logging to stdout).
At one point I needed to check a problem where file descriptors weren't getting created on iOS but the file handle was still being considered "valid" by the OS, and so I did parallel logging to stdout and to a file. That code got checked in, which is why we're here now.
The original intent was either-or. stdout by default, or to a file of your choice; never both. The original mechanism allowed you to switch back and forth between stdout and a file by setting the field to null or non-null. I'm not sure if logging to both is ever going to be useful other than diagnosing an esoteric OS bug like I was doing in iOS 7.
So, to fix this, I think the best course of action would be:
- KSLogger by default points to stdout.
- No other part of KSCrash may set the file pointer unless it's passing along an explicit user request.
- If the user requests logging to a file, it writes to a file instead of stdout.
- If the user sets logfile to NULL, it logs to stdout.
- The log hooks are fine, but your choice of action will be basically limited to changing how you format the log messages, since to remain async-safe you can't do anything beyond writing to files using the low level
write(), exactly like KSLogger is doing now.
There was a problem hiding this comment.
Ah, that explains a few things. I'll make the changes as you've outlined above. Thanks!
There was a problem hiding this comment.
Do we need to keep the kscrash_setAddConsoleLogToReport and kscrash_setPrintPreviousLog functions? They are plumbed up as properties on the KSCrash class as well. They are the ones using kslog_setLogFilename today. If we need to keep the behavior we need to introduce a way for the logger to log to a file or stdout, and a file used for the addConsoleLogToReport feature 😢
There was a problem hiding this comment.
Both of those are still needed.
KSCrash already stores a fresh logfile to disk on every run. When the app crashes, kscrash_setAddConsoleLogToReport tells KSCrash to read the logfile and add it line-by-line as an array of strings to the JSON crash report that's being written.
kscrash_setPrintPreviousLog tells KSCrash to look for a logfile hanging around from the last crash, and if it finds it, print it to the console. It's mostly to aid during debugging crash report generation so that you can quickly see how far the reporter got before something died.
There was a problem hiding this comment.
KSCrash already stores a fresh logfile to disk on every run.
Right, using kslog_setLogFilename, which I though we determined should not be called from KSCrash itself, unless it's passing along an explicit user request.
So to keep those two features we need to teach the logging framework to log to multiple files:
- the internal log file used by
kscrash_setAddConsoleLogToReport - whatever is set by the user via
kslog_setLogFilename
Or, we make KSCrash set a default kslog_setLogFilename (and leave stdout enabled), which can be overridden by the user calling kslog_setLogFilename which would then disable stdout, and then make the kscrash_setAddConsoleLogToReport feature use whatever filename was set (by the user or the default) instead of expecting the log to be in ConsoleLog.txt?
There was a problem hiding this comment.
Oh geeze. OK, forget all the BS I just spewed :P
I changed KSCrash awhile back such that the user no longer determines what the logfile name is on disk, because that's pretty much never useful. I changed it so that the logfile name and location is always the same, deterministic value so that it can add log files to reports, print previous logs, etc.
Since the logs are ALWAYS written to disk, and the user can determine whether to include them in reports or not, or print them after the fact, the only remaining annoyance is that it always prints log messages to STDOUT.
So what we actually need is a boolean flag telling it whether to also print to stdout or not (and default to FALSE). No more gating it on whether the report file path is NULL or not.
Sorry, been a long week!
There was a problem hiding this comment.
Ah, then I'm with you! 😄 No worries man, it's Easter vacation, I'm very grateful you are taking time to give feedback on these PRs!!
torarnv
force-pushed
the
logging-hook
branch
3 times, most recently
from
36f888a
to
abfc7b0
Compare
The 'basic' versions of the C and ObjC loggers have been retired, in place of just having the macro fill in default arguments for the full function. The Objective-C full function now only takes care of converting the CFStringRef into a C string, that is then passed on to the lower level function i_kslog_log(). The same goes for i_kslog_logC, which prepares the va-args, and forwards to i_kslog_log(). This is then the only place where the the level, file, line, and function are formatted and log output is written, which should make the code easier to maintain, and allows inserting API entrypoints in i_kslog_log().
Useful when wrapping KSCrash in a framework that has other ways to log than stdout/files. Will not affect file/stdout logging, so that those can be toggled independently.
Should we make |
|
Yes, it shouldn't be called by the user. |
|
Cool, will change that in a followup. |
This solves #218 for me, though a separate API to silence stdout with the default log handler would probably make sense too, so perhaps keep #218 open?