Slow Report, Why?

The databases we use this day are either Universe or Unidata (U2) from Rocket Software. These U2 databases, to put it mildly, are viewed quite differently. U2 databases are multivalued and sit in a database environment with limited tools from the vendor. The non-vendor tools are sometimes so costly, we still think U2 is still under IBM's tutelage.

Actually, the problem is that the U2 market is much smaller these days and never was that large to begin with. These non-vendors must price the tools accordingly to the possible number of sales which can be less than a thousand rather than many more times that for most other databases.

So several years ago, we decided we needed a report writer like the big boy databases. One of our staff members found BIRT from the open-source project Eclipse on one of their many searches. There was, however, a tiny problem with BIRT in that it did not work for our U2 databases. Nonetheless, there are mechanisms in BIRT to access other databases which they call Open Database Access or ODA. Thus, U2logic needed to produce an ODA for BIRT which we did. This ODA allows our team to use BIRT just like we are real big boy databases.

It took us a few months to convert all of our handwritten UniBasic coded HTML reports to BIRT format and many things surprised us. First, some of our reports finished in about 1 or 2 seconds running on the web when those reports ran in about 15 to 20 seconds in our prior format with our prior code. Second, our clients were so happy that they could request the same report in DOCX, XLSX, HTML, or PDF format without asking us to create a new version or option for each format they would like. Third, was that the reports that often took us 2 or 3 weeks to create were completed and tested in 3 or 4 hours and sometimes in under 1 hour. All of this definitely was a win-win for us and our clients.

One of these BIRT reports was a standard balance sheet which is a pretty standard report for all accounting systems. Initially, this report ran in about 2 seconds when we first installed it at one of our clients. About 18 months after installation they said the report was running a bit longer at 5 minutes. We did not think that was unreasonable since they were adding 50K in accounting journals to the system monthly which means they had about 1000K in records. We did what any "good" software company does: we ignored them and hoped it would get better by magic.

Of course, the problem got worse and worse because ignoring it never fixes it. By the time they brought it up the next time, the process now was running in about 90 minutes. A programmer was assigned to fix this. This programmer spent a few days and could not make it run any faster by cleaning up some archaic code, caching the code file reads, and switching from appending data to using LOCATE to build the array in display order. Needless to say, the client was not happy with us, and rightly so.

One of the problems with young programmers is that they are sometimes trained at code schools with very little knowledge of database design or how CPUs access the data from the database. Some of us older folks remember 6-bit architecture machines where having data meant mounting tapes for input and mounting tapes for output. This translates to an understanding of what you could do with limited resources versus today where U2logic stores data on a 100GB box running with 16GB of memory.

Here are some the questions we asked ourselves to diagnose this speed issue. 1) How many records are we trying to read through? 2) How long does it take to select the database file? 3) How long does it take to process the information to get in a format BIRT wants?

Our client had had about 1000K records when we first looked at the issue. Now, we count the file and they had over 10 million records. Well, based on our prior math the file size should have been around 2 to 3 million. No longer were they adding 50K records per month but that figure was over 150K per month or roughly triple what we thought.

Let's do some math. Five minutes of processing equals about 300,000 milliseconds or about .3 milliseconds to read each record. With the file at 10 million records, it was taking about .54 milliseconds to read each record or about double. Since this file is a dynamic hashed file we looked at how it was sized and found minimal overflow, so this was not the problem.

The selection of 100K records was about 300 milliseconds using a stand-alone process. The selection at 1000K records was about 2 minutes using that same process. The selection for 10 million records was 15 to 30 minutes using that same process.

Unfortunately, that was not the only problem. For grins, we used a pre-list to drop the selection from 30 minutes maximum to about 8 minutes but the report still took over 60 minutes to run. Where to look for the next problem was the refrain none of us asked each other.

Somewhere in a time long ago in a software shop off a freeway with a slow elevator and pitted parking lot, one of us remembered that if your internal arrays of data get too large the system starts to malloc memory and U2 gets slower and slower as the array gets larger and larger. Why would one of us be remembering this, oh because this programmer created a program that read 100 million-plus records into a program and tried to do a bubble sort on data that crashed the UNIX box running Unidata which reported: "Error on malloc a space (size=xxx), errno=xxx Memory allocation error. The requested size is too large. Install more physical memory or increase swap space."

Since our machine had enough memory and could malloc all it needed, it did not crash. Nonetheless, the process was quite slow because it was taking all of the memory to load 10 million records into an array for this program to run. Hey, we said to ourselves, this program looked good until our client "overloaded" their system was the statement from our programming group. Not helpful but maybe a little funny in our demented way.

The problem was solved, thankfully, by creating a daily summary file that had only the information needed for the balance sheet, profit and loss, and a few other reports. This file was not used for the online system just for BIRT. If you think about it, we created a data warehouse cube for this report run against. We created a new file and updated the programs to keep the data current. This file would have about 5 data fields and a simple structure that would involve 365 records created per year. We found this file could be selected by any criteria in about 50 milliseconds with 5 years worth of data.

After a day or two of changing the UniBasic program creating the BIRT data and testing it, we found the report ran in about 5 seconds. Needless to say, we were ecstatic but the client was not so inclined. The client felt we should not have ignored them and fixed this many months ago. Hopefully, these are lessons learned for us and we will never repeat them again!