If you have to handle LOBs, it’s worth checking for “unusual” activity. Here’s an example of unexpected behaviour that I came across a couple of years ago.
The client had a table with data that had to be written to a flat file so that a number of other databases could import it using SQL*Loader. The table definition and the query to dump the data are shown below – note, particularly, the CLOB sitting in the middle of the table:
Name Null? Type ----------------------- -------- ---------------- ID NUMBER(10) VIEW_NAME VARCHAR2(32) USER_ID VARCHAR2(16) XML_FILE CLOB FILE_PATH VARCHAR2(127) ACCOUNT_ID VARCHAR2(16) AREA_ID VARCHAR2(16) LABEL_ID VARCHAR2(16) COMPLIANCY_FLAG VARCHAR2(1) select id || chr(27) || view_name || chr(27) || user_id || chr(27) || xml_file || chr(27) || file_path || chr(27) || account_id || chr(27) || area_id || chr(27) || label_id || chr(27) || compliancy_flag from t1 ;
The dump code is fairly simple – it just concatenates the columns in order, inserting a separator between them using a value that’s not allowed to appear in the data. (The client’s code was a little more subtle, but essentially the same).
I’ve inserted 10,000 rows into this table, with 500 bytes of data for each LOB, and when I execute a simple; “select dbms_lob.getlength(xml_file) from t1;” it takes 20,653 logical I/Os – 653 for the tablescan and 2 to read each LOB value (since I’ve disabled storage in row).
So why, when I run the dump code, do I see the following stats – the number of buffer visits is obviously a little surprising but notice, in particular the number of “lob writes” and the number of “db block changes”:
session logical reads 1,840,063 db block gets 1,540,034 consistent gets 300,029 db block changes 550,037 consistent changes 550,015 free buffer requested 119,891 lob reads 10,000 lob writes 220,000
Despite all the block changes, by the way, the session generated less than 2KB of redo log – and that’s a bit of a clue to what’s going on.
Here are the results of the same job after I’ve optimised the code in two different ways:
session logical reads 240,006 db block gets 140,000 consistent gets 100,006 db block changes 50,000 consistent changes 50,000 free buffer requested 19,910 lob reads 10,000 lob writes 20,000 session logical reads 400,006 db block gets 280,000 consistent gets 120,006 db block changes 100,000 consistent changes 100,000 free buffer requested 29,907 lob reads 10,000 lob writes 40,000
Of course, you might be more interested in the timing rather than the simple counts – the original code used 13.95 CPU seconds, the best version 3.49 CPU seconds, and the third version 4.73 seconds – and it was the third option that we had to implement.
So where does the extra work come from? The answer is in the different versions of the code … the point at which you introduce the LOB into the list of concatenated columns makes a big difference:
select id || chr(27) || view_name || chr(27) || user_id || chr(27) || file_path || chr(27) || account_id || chr(27) || area_id || chr(27) || label_id || chr(27) || compliancy_flag || chr(27) || xml_file from t1 ; select start_piece || xml_file || end_piece from ( select id || chr(27) || view_name || chr(27) || user_id || chr(27) start_piece, /* */ chr(27) || file_path || chr(27) || account_id || chr(27) || area_id || chr(27) || label_id || chr(27) || compliancy_flag end_piece, /* */ xml_file from t1 ) ;
The minimum work appeared when the LOB was the last thing added to the concatenation; if the LOB wasn’t at the end of the list then every column (including all those chr(27)’s) resulted in the following extra work for every row selected:
session logical reads 16 db block gets 14 consistent gets 2 db block changes 5 consistent changes 5 free buffer requested 1 lob writes 2
Essentially, every time you add a piece on the end of the LOB, Oracle creates and updates a new temporary LOB (hence two lob writes). Since they are temporary LOBs – associated therefore with the temporary tablespace – all those “db block changes” don’t cause any redo to be generated, but the overhead is significant.
In fact, it’s quite easy to miss what may be the most significant figure – the “free buffer requested”. If you use code like this to dump a large amount of data you may find that the system starts doing more reads and writes because you keep demanding free buffers.
In the short term, we adopted the second, slightly more expense option – because the process was delivering data to lots of other systems to be loaded by SQL*Loader and the optimum code would have rearranged the column order and forced us to supply a code release to all those remote systems. The slightly more expensive code kept the result looking the same while concatenaring just one extra column afte the LOB.
Test carefully when you start using code that mixes concatenation and LOBs, and check for any unexpected increases in buffer activity.