I gave you a brief introduction to ORF 3.0 PowerLogs in my previous article, now I would like to tell you more about the details.

PowerLogs aim to provide much more detailed information than the current ORF text logs do. Some of this new data is needed for reporting and others are merely for the user, such as the subject of the email. Let’s see what’s new:

• Email subject. Yes, the logs will tell you the subject of the email :) This will help identifying false positives and emails in general. We have to admit that logging the Message-ID did not really work out, but we could not log the subject previously due to the ANSI charset limitation.
  Of course, this will only work at the On Arrival filtering point, as there is no such thing as “email” at the Before Arrival filtering point.
• Complete test log of every email. This is required by Reporting—in order to generate test effectiveness reports for individual tests, we must be able to tell how many emails the IP Blacklist or the Spamcop DNSBL checked and caught.
• List references. Got an email blacklisted by the Keyword Filtering, but you have no idea which one caused the blacklisting? No problem, the log will tell you which keyword filter it was. I mean, not only the keyword filter comment (if any), but the keyword filter itself. Similarly, it will tell you the related IP Whitelist, Sender Blacklist, DNSBL or SURBL expression. This also means that you will be able to generate reports about individual DNSBLs effectiveness (maybe not in 3.0, but in a later version—the data is there).

Some more unsorted facts:

• Logs and list references (see above) will be stored in separate files (n:1 relation, n log files and 1 reference file) to save disk space.
• Both files will be in regular CSV format, with Unicode UTF-8 encoding. No more “Unicode comment cannot be logged” complains :)
• Timestamps will be in Coordinated Universal Time (UTC), to avoid Daylight Saving Time (Summer Time) problems.
• Log file name format will be fixed and will always contain the date when the log was generated. ORF test logs offer flexibility in this regard, but unfortunately that flexibility adds lots of extra complexity to log processing . The date will be generated in UTC, which might be a bit strange for those whose time zone offset is more than 1-2 hours.

Obviously, the more data logged means larger log files. Lot larger. Due to this, real-time reporting with full log processing would have very poor performance. Our fine-tuned CSV reader has about 8Mb/s processing speed, which is nowhere near to the performance needed to generate yearly reports reasonably fast (it would take hours on a high-load server). Also, those who run servers with high load will have gigabytes of logs in a year, which they will barely keep, not even for reporting.

To reduce the time needed, ORF will generate preprocessed report files daily (or more often). As ORF users have to be able to generate reports for a specific time range, e.g. for Jan 1, 2006-July 1, 2006, we cannot just make an incremental report. Instead, full reports with a given resolution are needed and when the user requests a report for Q3 2006, generate a summary of these preprocessed reports between the above dates. Of course, preprocessed reports will also take disk space, so resolution might not be 1 second or 1 minute. As the range of reports and their exact contents are yet to be specified, the question of resolution is still open, but it may be 1 hour or 24 hours.

In my previous post, I told you about performance concerns of the ORF 3.0’s new Reporting feature. Alas, performance is not the only thing that slightly reminds me a design nightmare.

One significant problem with the current log format is that is does not contain enough data for reporting or the data contained is not in the required format.

• Logging of specific ORF events can be disabled. Not only they can be, some are disabled by default, for instance, logging Before Arrival whitelist/accept events is disabled in a fresh ORF installation. This makes it impossible to compile reports about whitelists at the Before Arrival filtering point, because the reporting engine has no clue what happens Before Arrival, except if the email (actually, the recipient) was blacklisted, which is logged.
  
  These defaults and the customizability aimed to simplify reading the logs and saving disk space. They certainly do, but they break reporting as well.
• Another scenario when data is missing is when we need individual test reports. Currently, ORF does not log what test was performed, expect if a hit (i.e. whitelisting/blacklisting) or error was generated by that test. We could make a pretty good guessing from the “Tests: “ log entries, but this would require sequential processing (see later) of the logs and not even in that case we would be informed why a hit did not occur (e.g. there could have been a list exception, like with the AD Exception List
• Individual list items cannot be identified from the logs. If you ever want to see how many emails your new Viagra keyword filter caught, the current log format offers little help. The comment of the keyword filter is logged, but that we rarely seen comments assigned to the keyword filters. It is not really user friendly this way, so we need to tell what exactly the keyword filter was. The current log format offers no way to fully identify the filter, though.
• Reports would need time-sequential log processing. While this sounds pretty easy, it has some challenges, because event date range cannot be determined from the file name for two reasons. First, the format can be configured by the user. Second, due to time zone changes, a log file can be re-opened, so it is perfectly expected that a log will have an event from 23:45 and the next event will be the same day 23:12.
  
  So we need to load all log files and sort all events into ascending order. Remember the performance concerns? Imagine sorting 365.000.000 event dates in real-time! In addition, some reports like Greylisting need the original order (time zone changes could break the original order).

For all the above reasons, you will not be able to generate reports from your current logs, unfortunately. We are working on a new log format (work name “ORF PowerLog” :), specifically built for reporting, but we plan this format to take over the role of the current ORF logs (not in 3.0 – the Log Viewer will not support PowerLogs, due to time constraints).

The benefits of the new logs are numerous, for instance, it will finally break the no-Unicode law and subject logging will be supported, but it will also provide full support to identify which keyword filter caused a hit.

The drawback is the size, of course. The more information need to be logged, the larger the log will be. We will do everything to make the new log format to be as compact as possible, but at least 200% growth can be expected.

I usually prefer simple design to rich, complex ones. In almost all cases, simple design offers numerous benefits, from fast and low cost implementation, easy modifications or extensibility. Yet, sometimes there comes a tiny little, unforeseen requirement which ruins the simple design and makes the entire design painfully overcomplicated.

In our case, this unforeseen requirement was a small feature of our order processing system, which sends Software Maintenance Agreement (SMA) expiration notification emails to the client. Notifications are sent 30, 10 and 3 days before the license expires, to remind the client to renew the SMA in time.

When the first 30-day reminders were received, many clients purchased the license right away (thank you!). Task completed, right? Not quite. When the first 10-day reminders were sent, we received a number of complaints from our clients that their SMA has already been renewed. It was not entirely surprising to us, because we knew the system will work this way, but we were surprised by the number of complaints. Even though we added a note

“If you already renewed this expiring license or you have an order in progress, please ignore this notification”

to the reminder later, it did not really help, so we had to come up with a solution.

But why reminders are sent once the SMA was renewed? The reason lies in the fact that our system does not track which SMA was renewed. When a new SMA order arrives, license is registered in the order history and that is all. If the client has multiple SMAs that have not yet expired, our system has no idea which license exactly was renewed. After all, why would it? From business perspective, we do not need that information, so the “design simple” principle said we should not add the complexity of license tracking to our system. However, without SMA tracking, we cannot tell if a particular SMA license was renewed or not.

Ah, devil is in the details.

To fix this problem, we decided to implement SMA tracking, but due to the extra complexity added, we expect this to stir things a little. We hope it will be less confusing than the repeated notifications (and will have another advantage – see below), though.

The disadvantages:

• SMA orders will require an ID to be accepted. This ID will identify the “parent SMA”, i.e. the license to be renewed. The required IDs will be provided on our website.
• If you have two SMAs that you bought separately (in two orders), you will not be able to just buy two SMAs to renew both. Instead, you will have to buy one and another one (two orders again). This is because you will be able to enter one reference ID only.
• Placing purchase orders and reselling ORF will become painfully complicated.

The advantages:

• No more “Your SMA expires in 10 day(s)” after purchasing a renewal.
• SMAs will actually start expiring when the SMA they renew expires. Previously, due to lack of tracking, SMAs started expiring immediately. This also caused some misunderstanding, but adding a repeated notice next to order links fixed things. I believe our clients will like this change, because they will not waste their money on the overlapping days when both SMAs are valid.
  
  This change, however, causes another problem, namely that purchasing 3 SMA renewals in a (referenced) row would result in 3 years of guaranteed updates. From business perspective, we do not really want this. We actually want our clients to buy the SMA renewal when it expires. This provides us calculable income flow and flexibility (the dream of every business :). To avoid the above problem, a limitation was built in: an SMA can be renewed first only 60 days before expiration. The limit can be, and will be, adjusted, if it is “too tight”.

We are looking forward to start this system, hopefully in the next two weeks. I hope this time choosing complex will be better than simple.

We wish you a Happy New Year! We’ll meet in 2006.

The role of the software architect is wonderful. As an architect, you face with a number of challenging design issues. You have to find the balance between time, resources, cost and requirements. You have to make compromises, even if you hate them. And at the end, you will blamed by the users :)

Now that I am designing the Reporting features of ORF 3.0, I find the role of the architect rather painful. If you have the strange passion to watch others making poor compromises, read on.

Due to the attention that we pay to performance, ORF is capable of filtering millions of email every day. It is not just marketing: we are aware of a few installations where ORF filters 1-3 million emails per day per server. I do not know what you say, but it is impressing for me. And it causes design headaches as well.

The new Reporting features in ORF 3.0 will be log-based, that is, reports will be derived from log data. As a single filtered email results in 1 to 2 or even more log entries, there would be about 365.000.000 to 730.000.000 log entries in a yearly report for a large client. In our logs (Verbose mode), the average log entry length is 190 bytes, so the size of the logs to be processed for a year will be around 69,350,000,000 – 138,700,000,000 bytes–that is, 64.6Gb – 129,2Gb.

That is awful lot of data to be processed. The Short log mode reduces this a little, but not that much. The log parser of ORF is optimized for speed, so its has pretty high throughput: about 22.07Mb/sec on my developer workstation. This means that parsing 64.6Gb log will take at about 2997 seconds or 50 minutes; in the less lucky case about 2 hours. And it is just parsing, transforming data for the reports will add significant delay. Alas, I do not really see how this could be made faster. Lots of information takes lots of time to be processed. Sorry guys, you will have to wait for your reports.

However, 90% of our clients fall in the 0-10,000 emails per day category, so most will have logs smaller by factor of 100 and 3.65 million entries will parse in 30 seconds. Or, if the client has faster disks, maybe even less – yes, the disk I/O can be a bottleneck.

This was speed. In my next post, I will talk about the significant concerns.