Hexlog, building a better logging system
Its been quite a busy couple of weeks for me. HexLicense has finally gotten a well deserved update and (drumroll) we have ported the codebase over to Firemonkey. I have deliberately waited a while with the Firemonkey edition, because compilers usually need a couple of releases before they become stable. And the same can be said about runtime libraries (I should know, I have created a few). I wanted to use FMX earlier but, it kinda died on me so many times that I gave up. Thankfully this is no longer the case and Delphi XE Seattle is a joy to work with.
Also, one of the coolest things these past weeks was returning to Smart Mobile Studio as a user. It’s really quite an odd experience because you get so locked into “author” mode when you have worked on a product for so many years. So when you sit down to actually use your own program as a means to an end, it’s a very different experience from looking at it purely architecturally.
I really love what we managed to do with Smart Mobile Studio. That might sound disingenuous since it originated with me, but somehow we captured something; some sense of creative freedom that I cannot find in giant productions like Visual Studio or QT C++. Naturally I’m biased, but I’m no stranger to self-critique either. But the speed at which I knock out a HTML5 or mobile application with Smart Pascal is just way beyond anything I can do in any other devkit. The only other development platform that have the same feel to it is Mono C#, which I love because it doesn’t contain all the .. bloat, I guess is a word, that large production environments insist on giving you. I mean, fire up visual studio and you have so many options – half of them that you will never use unless you specialize within a particular dicipline – that they just get in the way.
Anyways, Hexlicense “Ironwood” was written first and foremost in Smart Mobile Studio. We have started to port the code over to Delphi to make the Xmas deadline, but honestly: I’m so glad I could use Smart to prototype this product, because it would have taken me twice as long in Freepascal or Delphi. I’m not even sure I would have bothered if Visual Studio was my only option. Seriously.
Back in the saddle
For the past few years my life has revolved around Smart Mobile Studio and the companies I have worked for (a.k.a “the day job”). It must be at least 4-5 years since I actually sat down and built products, delivered components and offered up my services as a Delphi software architect. There havent even been any time for consulting or system design. With a full day job, two kids and a product you live and breathe for there is a limit to how much you manage. Add to that my back injury 4 years ago which rendered me unable to even walk and you get the picture; Thankfully my back is getting better. I do two rounds of boxing every week (or try to) and that has done more for my back than all the doctors and their witch-craft medicine combined.
It feels so good to create new products again. Products that are doable within a reasonable time-frame and that solve real-life practical problems (as opposed to having to solve potential scenarios that havent even occurred yet: the burden of the RTL architect). So while HexLicense for VCL and FMX is in the store, Ironwood is being ported to Delphi – I have decided to wake up another component-set that I initially created for myself. One that deals with a very practical and hands-on challenge, namely: HexLog.
Many years ago I was working for Hydro, which is the biggest oil company in Norway. Without getting to detailed (or breaking my NDA) logging was one of the problems we faced. With more than 50 Windows services communicating (read: 50 potential sources of bugs), the company’s lack of proper logging – logging in a format that made sense to people other than us developers (like system administrators, super-users and even insurance companies interested in locating where something broke down) made it almost impossible to work with the codebase.
So one day I had enough and sat down in my spare time to write a modular, thread safe, component based logging system that didn’t just “log some info”, but it did so by proxy. Meaning, that the writing mechanism(s) were isolated in separate components, abstracted from storage – which was isolated in other components. So when we needed XML logging we just hooked up the XML writer; when we needed RTF logging we hooked that up (and so on, for numerous formats).
You would think that Delphi developers in general had logging under wraps right? That is sadly not the case. Some people are very good at logging and have made it into a habit. But more often than not when I’m hired by a client – what do you think I find? Yup, plain old vanilla text-file logging. Which is fine as long as the coders have spent some time making sure the basics are in order. Sadly that is so rare it almost frightens me. Especially when I’ve upgraded software used by pharmacutical companies, doctors and organizations that really (really!) should do full journaling regardless of bugs or errors. In fact Norwegian law demands it in some cases; especially when medicine and prescription drugs are involved. If a doctor or nurse prescribes the wrong medication and a patient dies, the insurance companies will have a field day if there is no logging according to standards. And should it turn out to be the software’s fault.. well, let’s just say there is a reason only large companies operate with “within the hour response time” in their service agreements.
So what are the criteria people tend to forget?
- File locking issues. It will happen the moment more than one process or thread targets a file
- Making sure the information that is logged is organized by sections, visually distinct in the file
- Making sure time and dates use UTC or ISO formatting
- Logging the actual user, not just the program identity
- Using mutexes and read-write synchronization when multi-threading is involved
- Avoiding interface communication from threads without proper understanding of calling conventions and compartment schemes
- Using memory mapped files rather than torturing the filesystem with an onslaught of IO calls
- Use tab indentation to make the logs easier to navigate for the human eye
- The list goes on ..
The most important oversight is not on the list, it’s actually something as simple as logging information that human beings can read, as opposed to adapting the information to what the computer wants to work with. A dentist wont know what to do with a stack-trace or “an error occurred executing MySQLQuery1.Execute”. But he or she will understand a log that states – in plain text – “could not store prescription for patient John Doe, the database reports the disk as full. An email has been sent to the administrator“.
You don’t have to be a programmer to replace a disk or move the database to a better location. But the log must make sense. It should just be there, not getting in the way yet easily accessible.
Journaling and big-data
When you are logging every action an oil-pump (and its regulators) do for 24 hours, logfiles can grow into the gigabyte range. Can you imagine one gigabyte of messy, purely technical jargon to wade through when a critical system is down? Well I can, because that’s exactly one of the things I faced 12 years ago when I was hired to “fix” a couple of bugs. A couple of bugs turned into 2 years of re-writing the entire system from scratch. Notepad crashed when it tried to load the original log-files.
The system was all written in Delphi 4, breaking every rule known to object pascal developers even back then. Like services opening forms and forms using DDE to communicate. It was a miracle that it had worked to begin with.
This is where I decided to write a journaling system that would present me, the programmer, with a unified API for writing, reading and even updating log-items stored in multiple files. So you can set a limit to how many log-items one file can contain, and when the log reaches that limit – it create a new file automatically for you. It takes care of everything in the background, keeping track of the files and their content through an index files. This solution helped solve the problem of monster log files. And you know what? That was the core bug in the system. They had used TStringList to load in the text file, append one item, then saved it back out again. Loading almost a gigabyte of raw text while trying to keep up with GPIO signals firing like mad. So yeah, logging does matter!
HexLog naturally implements this, now even faster than before due to Delphi’s dictionary classes and clever use of balanced trees. The best is that the writer mechanism applies to this type of journaling as well. So if you prefer XML thats not a problem, nor JSON, nor RTF for that matter. I’m even throwing in a PDF writer in update 1.
And did I mention both local logging and network logging? And that you can read the logs via a fancy HTML5 dashboard in any browser, both locally and remotely?
Reading more about HexLog
If you find the topic interesting and worthwhile, head over to my company website and read the release statement here: www.quartexcomponents.com. We dont take orders just yet, but it should ship out in the beginning/middle of next month.
And yes, there will be a server edition both for native Delphi and node.js, so there is a lot of value for money in this package.