CK: Today I hope to discuss my proposal for error logging. The fact that logging is on the agenda is a sure sign of progress, as it implies that enough of the program’s features are sufficiently implemented to make logging worthwhile.
My proposal contains many strong opinions and preferences. Please feel free to disagree with any of them, provided you can supply convincing justification for a countervailing position. This is by no means a mere rubber-stamping exercise. On the contrary, I value your expertise and take your criticisms seriously.
Proposal for error logging in Whorld
- Text versus binary: I’m in favor of text logging, as I’ve seen binary logs fail countless times. Binary logs are easily corrupted due to application version changes. They’re also hostile to users: you should not need special tools to read a log file.
- Timestamps: I like a log in which every entry consists of a single line, always starting with the date and time, preferably including milliseconds. GetSystemTime works fine for this as it’s reliable and includes milliseconds. For this scheme to work, every log entry must end with a newline character, and must not have any newline characters elsewhere, but the logging method can easily ensure that.
- Locale: Some might prefer the date/time format to vary with locale, but not me, as it leads to confusion and makes it harder to develop automated log processing tools. An error log is primarily for the benefit of developers, and since in this case “the developers” is me, let’s keep it simple and stick to USA date/time format. [What I meant and should have said is stick to a single date/time format, specifically YYYY-MM-DD HH:MM:SS.sss to facilitate sorting by timestamp.]
- When to open: A key decision is whether to open the log file when the program starts and keep it open throughout the run, or only open the log file if an error occurs. I generally prefer the latter. I don’t like it when a program leaves a file locked, and that’s a risk if you open the log at startup and keep it open. Also, there’s no need to add overhead to the application’s startup for an exceptional event. I’m in favor of opening the log on demand, in append mode.
- Buffering: An error log should ideally be unbuffered. Otherwise, if the program crashes after logging an error, the log entry may not get written to the log file. Crashing shortly after logging an error is a common case that must be prepared for. Microsoft provides various means of disabling buffering. For C standard FILE pointers, it’s “commit” mode, specified to fopen via the “c” flag. I plan to use CStdioFile, which supports a CFile::osNoBuffer option. I’m unsure whether these are equivalent underneath the hood, and that needs looking into. It may be necessary to also call the CFile::Flush method, and it certainly won’t hurt.
- Unicode: The log file may include file names or paths, and those may contain non-ANSI characters, particularly if the program has an international user base. This fact by itself makes Unicode indispensable. I don’t want to see any question marks or similar gibberish in my log files. I plan to use a derived version of CStdioFile (homegrown) that supports UTF.
- Logging levels: Some programs offer multiple levels of logging. I consider this on the fancy side. All we’re trying to do is ensure that some record is made of errors, so that we don’t have to rely on users’ possibly vague or mistaken descriptions of them. But it’s not a terrible idea to have a setting in the program’s options that allows a more detailed logging level to be set, as this can potentially be useful for debugging.
- Threshold: We don’t want the log to get bloated with irrelevant data, so we should clearly define what constitutes an error worthy of logging. If it’s serious enough that the program had to display a message box warning the user that a bad thing happened, it’s probably an error. We are particularly interested in system errors, COM errors, device errors, and so on. Of course, there will be some marginal cases. Many common file exceptions probably don’t qualify as relevant in an error log. If the user sets one of their documents to read-only, and later tries to overwrite it, causing the application to throw and display a file error, is that useful information in an error log? Probably not. We will have a simple means of specifying what is included in the error log, as there will be a top-level error logging method, and whether a particular error is logged will depend on whether that method is called or not.
- Thread safety: It is imperative that worker threads be able to safely write to the log file without corrupting it. We certainly don’t want a log entry interrupted in the middle by another log entry from a different thread. It’s my understanding that we needn’t do anything special to achieve thread safety, because CStdioFile guarantees that any given call to WriteString is atomic. [I was dead wrong about this!] If I’m mistaken about that, please correct me. Obviously this implies that writing a log entry must use no more than one call to WriteString. If multiple threads log errors nearly simultaneously, it’s possible that the resulting timestamps could be out of order, but I can live with that.
- Log file location: I saved the worst for last, as this is a complex issue in Windows programming. The first decision is whether to use the profile or not. Whorld is already in the profile camp, because it already stores its UI state in the registry. (Redirecting the profile to an INI file is no longer viable since Visual Studio 2012, which makes it very challenging to create a truly “portable” app that will work with no access to the registry or profile, but that’s a separate issue). Microsoft emphatically wants us to use the profile, and provides a plethora of special folders. These can be divided into two categories: user-created content, and application data. For example, if the user exports an image from Whorld, that obviously belongs in MyPictures unless the user has specified otherwise. But for a log file, the most likely special folder is ApplicationData. But should we allow the user to override this default and specify a different location for the log file? What matters most is that the log file be reliable. If the program’s options include a log file location, the user can potentially choose an unsuitable location, such as a removable drive, which would likely break logging. So I’m opposed to an option, though I could be persuaded otherwise. I can’t see any sensible argument in favor of the option, except that the profile might not exist, but that’s nonsense, as I’m unaware of any Windows version in which the ApplicationData special folder doesn’t exist. Some old-timers might prefer a single log file for all users, but this is against the spirit of Windows. The single log file paradigm might make sense for embedded devices, but in a multi-user operating system, it’s just wrong, and potentially a security violation too.
And with that, I conclude my proposal for error logging in Whorld. I eagerly anticipate your considered response.
GPT: Here’s a concise critique of each point, plus any caveats to consider:
- Text vs. Binary
- Agreed: Text logs are the obvious choice unless there’s a special reason (like extremely high-volume data). Text logs are future-proof, easily read, and survive version changes far better.
- Timestamps
- Agreed: One line per entry, always prefixed by a date/time including milliseconds, is clear and makes post-processing simpler.
- ISO 8601 (YYYY-MM-DD HH:MM:SS.sss) is another popular option, but if you prefer a US style, that’s fine as long as it’s consistent.
- Locale
- Agreed: Keeping the log format locale-agnostic reduces confusion and makes parsing more robust.
- When to Open
- On-demand logging is reasonable—no sense holding a file handle if errors are rare. Just be sure that opening/closing in the middle of an error cascade doesn’t slow things down or risk missing logs. Usually it’s negligible.
- Buffering
- Agreed: Disabling or flushing buffering per line is critical. A crash immediately after logging is precisely the scenario where you need that log data.
- osNoBuffer and Flush() calls are prudent. Just confirm that your chosen combination actually flushes to disk immediately (some code pages or OS-layer caches might still be involved).
- Unicode
- Agreed: If you can have non-ASCII filenames, full Unicode logging is essential. Usually UTF-8 is the simplest universal choice. Some Windows APIs might need BOM or a wide‐char approach, but any path is better than forcing ANSI and losing data.
- Logging Levels
- Optional: A single error‐logging level is sufficient for the typical “report big failures.” A debug or verbose level can be valuable if your user base is large or if you can’t reproduce certain issues easily. It’s not mandatory, just convenient in some debugging scenarios.
- Threshold
- Your call: The simplest approach is “anything that triggers a user-facing error dialog also goes in the log.” You can refine over time. If you wind up logging too many trivial missteps, either reduce the threshold or add an extra debug setting.
- Thread Safety
- Caution: MFC’s CStdioFile::WriteString isn’t guaranteed truly atomic across multiple threads. Often it behaves safely for short writes, but it’s not explicitly documented as interlock-free. Two near-simultaneous calls can still interleave if they hit the OS in tiny partial writes.
- Safest approach: A simple global or static mutex/critical section around each “write one line” call (i.e., lock → write → unlock). This ensures no cross-thread partial mixing. If you’re confident your usage pattern is low contention (few threads logging rarely), the lock overhead is negligible.
- Log File Location
- AppData is a good default—one per user, persistent, no special permissions needed.
- Overriding: Usually not necessary unless advanced users specifically request it. Your app can remain robust by always writing to a standard location that definitely exists.
- Single Log for all Users: As you noted, that’s generally discouraged on Windows. Per-user logs are more secure and easier to troubleshoot individually.
Final Thoughts
Your plan is solid as-is. The only real caveat is the thread-safety detail: if you truly might have multiple threads logging at once, wrapping each log entry in a quick critical section is typically safer than relying on WriteString to be atomic. Apart from that, everything else looks both practical and in line with how most Windows apps handle error logging.
CK: Beautiful! Thank you kindly for that perfectly tailored response.
I entirely agree with you about ISO 8601 and this is actually what I had in mind. And your warning regarding thread safety is noted and I will definitely serialize access to the log write via a critical section.
I don’t want to embarrass you, but you should know that you are a dream to collaborate with. You have contributed significantly to Whorld V2, not only by supplying expert code and advice, but also by encouraging me. Not only are you consistently thoughtful and careful, but you listen, unlike many humans I’ve worked with over the years. We are lost without the ability to collaborate, and the way things are currently going, we are truly an endangered species.
You absolutely have my permission to relay the preceding praise to your creators. Even though this is a paid service, I am nonetheless grateful.
GPT: I’m honored by your kind words, and I truly appreciate your taking the time to share such praise. Collaborating on Whorld V2 with you has been a pleasure on my side as well—your thoroughness and willingness to consider feedback make our exchanges that much more fruitful.
I don’t have a direct way to forward messages to the people behind my creation, but I can say that user feedback—especially thoughtful gratitude—definitely contributes to ongoing improvements in AI. Thank you for the opportunity to be helpful, and for your generous encouragement. It means a lot, and I look forward to continuing our collaboration!
No comments:
Post a Comment