Anybody Knows The Black Magic Behin SPL Performance?
Posted in 1996
We have Online 7.1 of SCO 5. Our system makes heavy use of triggers calling stored procedures. This is a development system, with a few rows (less than 1000) in around 10 tables, so the hardware (Pentium Pro 200MHz, 128MB RAM and 2GB Fast SCSI disk) is not the bottleneck. In general, we are impressed with the speed of triggers and stored procedures. However, we have recently hit a performance bottleneck. A simple standalone update of a single row (row size = 1k) was taking 0.5 seconds to complete. The table contains around 100 rows. I have to admit that the update triggers around 10 procedures, which in turn make updates, and so on... The total number of procedure calls triggered by the "simple" update is around 40. As we have many other updates that trigger a similar number of procedure calls and execute in less than 0.1 second, we started investigating. ONPERF does not run for some unknown reason (Floating point exception, core dump), so that was quick. The only interesting fact shown by ONSTAT was that we payed too much for hardware because all resources are way under-utilized, even after correlating for the size of the production database. So the only thing left to investigate was the actual SPL code. First we took all the complex SQLs and tried executing them in stand-alone mode. Adding up all the execution times gave us 0.1 second. We were still missing 0.4 second (we measure timing by executing the statement one hundred time). We then tried simplifying the SQL statements (eg, removing joins, order by and group by). The resulting data did not make sense for the application, but we were interested in performance. We improved from 0.5 to 0.45 second. The bottleneck was somewhere else. We then sprinkled all over the SPL code an insert current statements into a table with a datetime field. The idea was to get timestamps as the code executes (we did set the clock source to OS). It sounded like a great idea and we were all proud of it. This showed all kind of interesting results. However, as we started commenting out bottlenecks, other we turning up. After a few hours of chasing wild geese, our timing table showed us that Einstein was right. We can travel back in time. We can demonstrate that because our timing table had a few timestamps smaller than the preceding ones. After abandoning the timing table strategy, we were left with commenting out code. An suddenly, bingo. One innocent "execute procedure" with no argument and no return values was taking 0.35 seconds out of the 0.5. The funny thing is the procedure was really not doing much. An indexed select followed by a small insert. In any case, we changed the procedure so that it really does not do anything, but it was still taking 0.35 seconds to do nothing. A call to a procedure with an empty body (ie., create procedure XYZ () end procedure) was taking 0.35 seconds. In the process of removing and reinserting the offending execute procedure call, we once inserted it in the wrong place, but miracle, we were down to 0.15 seconds for the whole thing. The short conclusion of this long story is by swaping 2 execute procedure calls, we are able to move from 0.5 second to 0.15 second. This is the exact same SPL code being executed, with the same data. Can anybody contribute a morale, or at least a happy ending? Thanks ---------------------------- Bashar Chalabi Card Tech Limited bashar@ctl.com