Opened 9 years ago

Closed 9 years ago

Last modified 8 months ago

#9260 closed patch

OSYSTEM: Basic logger

Reported by: lordhoto Owned by: lordhoto
Priority: normal Component: --Other--
Keywords: Cc:
Game:

Description

This patch is a proof-of-concept implementation of a basic text only logger.

The "main" addition is the class Log (placed in backends/log/log.[cpp,h]). It has some basic features which can be used for different OSystems, i.e. it optionally outputs time information based on OSystem::getMillies. Apart all it can do is output simple start/end text and it automatically starts with the ScummVM version strings.

I also hooked it up with the SDL backend as an example. Currenlty the output file is always "~/scummvm-log" for testing reasons, thus it should only work fine on UNIX-like systems.

Current TODOs:

- Discuss what exact functionallity we need, i.e. is the simple text output enough?
- Document the class and its methods/members.
- Discuss where/how we want to store logs on our SDL targeted platforms (and implement it)
- Currently OSystem_SDL::logMessage will always call the logging method so that the logger will output the time. This is not really nice when debugN is used. We would need to find some nice way of assuring that the time information is only printed *after* a new line on the next call, to have some nice looking output.

Ticket imported from: #3115757. Ticket imported from: patches/1365.

Attachments (1)

log.patch (5.5 KB) - added by lordhoto 9 years ago.
Patch against trunk r54415

Download all attachments as: .zip

Change History (7)

Changed 9 years ago by lordhoto

Attachment: log.patch added

Patch against trunk r54415

comment:1 Changed 9 years ago by fingolfin

Great that you work on this!

Good idea to prefix the log data with info about the ScummVM version -- why not go even further and also print gScummVMFeatures and the current time & date according to OSystem::getTimeAndDate ? The date/time could even be used for the timestamp: A timestamp of the form "YYYY-MM-DD HH:SS" might be more readable anyway (and always occupies the same number of chars, making for either viewing / editing).

Regarding the TODOs you listed (and beyond):
- Simple text output seems fine to me. I am not quite sure what else you have in mind here, though?
- Log location: On Mac OS X, this would be either ~/Library/Logs/ScummVM.log (file name could be changed appropriately, of course), or we add a subdirectory ~/Library/Logs/ScummVM/ and store files in there.
* Making explicit what lurks implicitly in your TODOs: We need to decide whether to use a single log file, or multiple logs, and on filenames.

Right now I would prefer to go with the "single log file" approach.
A single log file is very easy to understand for the user, and there is little risk of the user picking "the wrong one". It is also easiest to implement for us. E.g. no need to rotate log files to prevent the disk from filling up with lots of "-d9" log files.

Potential drawback is that the user must remember to copy it right away, before re-starting ScummVM, else it is lost. This is mostly a problem for "rare" hard-to-reproduce issues. If the user can easily reproduce it, then they are just fine either way. Moreover, if we crash into the debugger console, we could display a text there like "If you want to file a bug report on this, you can find a log file with relevant info in location XYZ. Please copy it NOW, before restarting ScummVM, otherwise it will get overwritten." Well, something like that, at least.

Also, for MD5 reports (where we'd ask the user via a GUI dialog to email use the log file), this is no problem.

Regarding the formatting: Yes, we should only print the timestamp after a newline (i.e. at the start of every line). I think the plain and obvious way is the nicest here: Add a flag "atStartOfLine" in class Log, which is initially true. Then Log::print() could look like this (untested, may not even compile):
void Log::print(const char *message, const bool printTime) {
if (!_stream)
return;

while (*message) {
if (_startOfLine) {
_startOfLine = false;
if (printTime)
printTimeStamp();
}
const char *msgStart = message;
// scan for end of line/string
while (*message && *message != '\n')
message++;
if (*message == '\n') {
message++;
_startOfLine = true;
}
_stream->write(msgStart, message - msgStart);
}

_stream->flush();
}

Regarding the platforms, we'll have to notify porters to get them to join the "discussion. But we can do that after committing an initial version of this code, I think.

comment:2 Changed 9 years ago by fingolfin

For a readable version of Log::print, see http://pastebin.com/Atm95qak

comment:3 Changed 9 years ago by lordhoto

Sure additional information at the start of the log would be nice. The ScummVM version looked the most important thing there though. Will add the features and the date too then.

About using the getTimeAndDate as timestamp: Aye that is possible, I just used getMillis, since I think some backends provide only dummy outputs for getTimeAndDate (like the N64, but it also increases the value over time IIRC). Guess using a getTimeAndDate based might still be fine, since the backends have control over whether they want time or not.

About your Log::print suggestion, yeah I thought about that, but it felt a bit annoying. Since you think it's fine I'll just use that then. :-)

I have no problems with first committing my patch (probably only the Log class itself though, not how it's hooked up in SDL) first and then starting a discussion about the filenames/paths/etc.

About the "text only" bits. I actually was not talking about plain text or something else. But rather maybe we should also extend backends so that they can support say outputting the gameid when a game is started etc. That feels like useful information. Of course this is rather some OSystem specific addition, i.e. to have some callbacks on certain events from the codebase (or routing it through debug from the codebase, but maybe the backends have other internal things to handle on game start etc.).

Another nice addition would be to say make screenshots on certain events, like warning/error, and maybe bundle those in a tar file (or some simple non-compressed container format) and add a line with the filename in the log on such occasions.

comment:4 Changed 9 years ago by lordhoto

I made the changes you proposed and committed the basic Log class now (r54451). I will write a mail to -devel to discuss the points you mentioned.

comment:5 Changed 9 years ago by lordhoto

Owner: changed from fingolfin to lordhoto
Status: newclosed

comment:6 Changed 8 months ago by digitall

Component: --Other--
Note: See TracTickets for help on using tickets.