4

I am having performance issues when extracting BLOBS from an oracle 10gR2 10.2.05 database I administer. I have around 400 files stored as BLOBS that I need to write out to the file system. Below is my code. When I execute this procedure the first 8 or so files are written within a couple of seconds and from there things slow down exponentially, somewhere around 1 file every 40 seconds after the first 8. To me this doesn't make any sense, why would the first 8 files be fast but after that everything slows down. I have tried running this as a stored procedure, changing the UTL_FILE.fopen to "wb" (write binary), and also using a NFS mounted file system so as not to impede the performance of the database. None of this has had any impact. At this rate it is going to take me 6 hours to extract 400 files that average around 1.5MB each. Does anyone see anything wrong with my code or know of a better way to do this? By the way I used this example code found here http://www.oracle-base.com/articles/9i/ExportBlob9i.php as a starting point.

Thanks for any help!

DECLARE
  TYPE comment_text IS TABLE OF documents.comment_text%TYPE;
  TYPE localdata IS TABLE OF documents.localdata%TYPE;
  l_file UTL_FILE.FILE_TYPE;
  l_buffer RAW(32767);
  l_amount BINARY_INTEGER := 32767;
  l_pos INTEGER := 1;
  l_blob localdata;
  l_fname comment_text;
  l_blob_len INTEGER;
  l_x NUMBER := 1;
BEGIN
  SELECT comment_text, localdata
  BULK COLLECT INTO l_fname, l_blob
  FROM documents
  WHERE user_id='BILLYBOB';
  IF SQL%ROWCOUNT =0 THEN
    DBMS_OUTPUT.PUT_LINE('No records found!');
  ELSE
    FOR i IN l_fname.FIRST .. l_fname.LAST
    LOOP
      l_blob_len := DBMS_LOB.getlength(l_blob(i));
      DBMS_OUTPUT.PUT_LINE(l_blob_len);
      l_file := UTL_FILE.fopen('BLOBS',l_x || '_' || l_fname(i),'w', 32767);
      l_pos := 1;
      l_x := l_x + 1;
      WHILE l_pos < l_blob_len
      LOOP
        DBMS_LOB.read(l_blob(i), l_amount, l_pos, l_buffer);
        UTL_FILE.put_raw(l_file, l_buffer, TRUE);
        l_pos := l_pos + l_amount;
      END LOOP;
      UTL_FILE.fclose(l_file);
    END LOOP;
  END IF;
END;
spaghettiwestern
  • 393
  • 1
  • 6
  • 17

1 Answers1

1

I'm pretty sure you shouldn't fetch all BLOBs into an array at the start of the procedure. Since you read the BLOB data and never actually close any lob locator, Oracle has to keep all this info in memory. I would guess this is a case of memory overfill.

Try this instead:

CURSOR cc IS (SELECT ...)
BEGIN
   OPEN cc;
   LOOP
      FETCH cc
         INTO l_fname, l_blob;
      EXIT WHEN cc%NOTFOUND;
      l_blob_len := DBMS_LOB.getlength(l_blob);
      DBMS_OUTPUT.PUT_LINE(l_blob_len);
      l_file := UTL_FILE.fopen('BLOBS', l_x || '_' || l_fname, 'w', 32767);
      l_pos  := 1;
      l_x    := l_x + 1;
      WHILE l_pos < l_blob_len LOOP
         DBMS_LOB.READ(l_blob, l_amount, l_pos, l_buffer);
         UTL_FILE.put_raw(l_file, l_buffer, TRUE);
         l_pos := l_pos + l_amount;
      END LOOP;
      UTL_FILE.fclose(l_file);
   END LOOP;
   CLOSE cc;
END;
Vincent Malgrat
  • 66,725
  • 9
  • 119
  • 171
  • I tested your code and there is no difference. However the DBMS_LOB.close throws the following error: 22289. 00000 - "cannot perform %s operation on an unopened file or LOB" *Cause: The file or LOB is not open for the required operation to be performed. *Action: Precede the current operation with a successful open operation on the file or LOB. – spaghettiwestern Dec 09 '10 at 00:26
  • @spaghettiwestern: My guess seems to have been wrong. However I tried to reproduce your setup and I was unable to notice the writes getting slower (my setup involved 1000 files of about 1.5MB each). In your case, since the first 8 writes seems to be OK performance wise, I would suggest splitting the work in small batches. – Vincent Malgrat Dec 09 '10 at 11:56
  • Thanks for your input and testing results, much appreciated!!! Interesting how you do not seem to have the same problem, what version of Oracle are you running? When I modify my procedure to take an argument and only allow one BLOB extraction at a time and then in a plsql block use a loop to drive my procedure then I do not have the slowdown problem. In fact it finishes extracting 700MB in about 40 seconds, where as the original code sample I posted here would take hours to finish. – spaghettiwestern Dec 09 '10 at 17:38
  • @spaghettiwestern: I did my test on a 10.2.0.3 db. Can you try with an explicit cursor instead of an implicit cursor? (I updated my answer, though you will have to adjust your `DECLARE` section). I'm wondering if maybe the hidden batch fetching of the implicit cursor (10g feature) is fetching too much data here. By the way I'm testing on a non busy test server with lots of available memory, this may be why I can't reproduce your result. – Vincent Malgrat Dec 09 '10 at 17:55
  • @Vincent - The explicit cursor produces the same results, it runs slow. I am also using a idle development server with plenty of ram and cpu. I think the problem I am seeing has something to do with DBMS_LOB.read, like it is filling up some sort of buffer or something. If I comment out the UTL_FILE.put_raw in my original code sample things still run slow so I know it has something to do with DBMS_LOB.read. – spaghettiwestern Dec 09 '10 at 19:19
  • That's a pretty severe slowdown for just a buffering issue. Have you tried profiling it with sql_trace? – JOTN Dec 09 '10 at 20:15
  • @JOTN - I will give sql_trace a shot tomorrow when I get a chance. – spaghettiwestern Dec 10 '10 at 04:16
  • Something I noticed is that when I run my original code but conditionally only extract files that are less than 100KB then I encounter no performance issue, it is only on the larger files say 1200KB that I encounter the performance issue. I ran the sql_trace and to my eyes its telling me there is excessive disk IO, someone correct me if I am wrong, here are the totals; CPU=166.06, elapsed=162.76, disk=1704593, query=11373096 – spaghettiwestern Dec 10 '10 at 21:49
  • I ran DBMS_PROFILER against my original code and the bottle neck seems to be with the DBMS_LOB.read taking the most total_time at almost 3x the UTL_FILE.put_raw total_time. – spaghettiwestern Dec 10 '10 at 22:58