I have recently come across an interesting issue related to concurrent data loading into the Oracle database using sqlldr’s direct path mode. Although I investigated the situation on 12.1.0.2, I found that the same holds true in 19.4 as well when using the defaults. I reconstructed the case, although it is simplified a little to bring the point home.
The environment I used to put this post together is Oracle Restart 19.4.0 on Oracle Linux 7.6.
Test overview
For this test I am running concurrent sqlldr sessions to demonstrate the case. I am conscious of that fact that I could have used external tables, but then I wouldn’t have been able to write this post :)
Assume there’s a table named t2:
SQL> create table t2 as select * from dba_objects where 1 = 0; Table created.
I am planning on populating the table with data in CSV format. Using sqlcl it is dead easy to create an input file, simply specify the /*csv*/ hint in your query and spool the output to a file: job done. The resulting input file is named t2.dat.
Next up is the control file. I am a creature of habit and tend to use a control file although I could have tried the same process using express mode.
Using the documentation I figured the following control file should do. Since it’s easy enough to forget passing direct=true to the command line I added it to the options clause. When using sqlcl to create a CSV file it adds the column headings in line 1, and they won’t load so I’m skipping these records. Here is the full control file:
options (direct=true, skip=1) load data infile 't2.dat' into table t2 append fields csv without embedded date format 'dd-mon-yy' trailing nullcols ( OWNER, OBJECT_NAME, SUBOBJECT_NAME, OBJECT_ID, DATA_OBJECT_ID, OBJECT_TYPE, CREATED date, LAST_DDL_TIME date, TIMESTAMP, STATUS, TEMPORARY, GENERATED, SECONDARY, NAMESPACE, EDITION_NAME, SHARING, EDITIONABLE, ORACLE_MAINTAINED, APPLICATION, DEFAULT_COLLATION, DUPLICATED, SHARDED, CREATED_APPID, CREATED_VSNID, MODIFIED_APPID, MODIFIED_VSNID )
With the prerequisites at hand I’m ready to perform some testing.
Test #1: concurrent sessions using defaults
First of all, what happens when starting 5 concurrent sessions? Will they complete? Let’s try this in bash:
for i in $(seq 1 5) ; do echo starting iteration $i sqlldr /@loader control=t2.ctl log=session_${i}.log & done
This ran to completion without any visible errors, but I prefer to run sanity checking anyway. The first thing to do is to see if all records have been loaded. The input file contains 73148 data records by the way.
$ grep 'Rows successfully loaded' session*log session_1.log: 73148 Rows successfully loaded. session_2.log: 73148 Rows successfully loaded. session_3.log: 73148 Rows successfully loaded. session_4.log: 73148 Rows successfully loaded. session_5.log: 73148 Rows successfully loaded.
So this looks ok, what about the run times?
$ grep '^Run' *.log session_1.log:Run began on Mon Jul 22 21:32:31 2019 session_1.log:Run ended on Mon Jul 22 21:32:44 2019 session_2.log:Run began on Mon Jul 22 21:32:31 2019 session_2.log:Run ended on Mon Jul 22 21:32:40 2019 session_3.log:Run began on Mon Jul 22 21:32:31 2019 session_3.log:Run ended on Mon Jul 22 21:32:46 2019 session_4.log:Run began on Mon Jul 22 21:32:31 2019 session_4.log:Run ended on Mon Jul 22 21:32:48 2019 session_5.log:Run began on Mon Jul 22 21:32:31 2019 session_5.log:Run ended on Mon Jul 22 21:32:42 2019
All in all these loads completed in a reasonably short time. Some took longer to finish than others though. That made me curious and I logged into the database to see what was going on. I never consciously saw this event:
SQL> select sid, event, state from v$session where program like 'sqlldr%'; SID EVENT STATE ---------- ---------------------------------------------------------------- ------------------- 44 kpodplck wait before retrying ORA-54 WAITING 52 kpodplck wait before retrying ORA-54 WAITING 54 kpodplck wait before retrying ORA-54 WAITING 290 Data file init write WAITING 291 kpodplck wait before retrying ORA-54 WAITING SQL>
Using the output from my above query I could see that one session was active, all the others queued up behind it. Interestingly there is no “enq: TM – contention” which you’d see with direct path inserts in sqlplus for example:
-- in session 1 SQL> insert /*+ append */ into t2 select * from dba_objects; 73157 rows created. -- notice there is no commit! -- Session 2 waits ... SQL> insert /*+ append */ into t2 select * from dba_objects; -- the DBA sees it all: SQL> select sid, event, state from v$session where username = 'MARTIN' SID EVENT STATE ---------- ---------------------------------------------------------------- ------------------- 51 enq: TM - contention WAITING 270 SQL*Net message from client WAITING
What’s even more interesting is this: ddl_lock_timeout which I thought might have helped, has no effect on sqlldr operations:
SQL> show parameter ddl_lock_timeout NAME TYPE VALUE ------------------------------------ ----------- ------------------------------ ddl_lock_timeout integer 0 SQL>
The parameter isn’t set at all, yet I could see “kpodplck wait before retrying ORA-54” which is strange. ORA-54 is of course the dreaded “resource busy and acquire with nowait specified” error. I managed to trace kpodp back to the direct load path functionality.
Without the ability to control waiting via a database parameter I am aware of, there must be some other timeout. And sure enough, there is:
$ time sqlldr /@loader control=t2.ctl SQL*Loader: Release 19.0.0.0.0 - Production on Mon Jul 22 21:46:59 2019 Version 19.4.0.0.0 Copyright (c) 1982, 2019, Oracle and/or its affiliates. All rights reserved. Path used: Direct SQL*Loader-951: Error calling once/load initialization ORA-00604: error occurred at recursive SQL level 1 ORA-00054: resource busy and acquire with NOWAIT specified or timeout expired real 0m32.038s user 0m0.011s sys 0m0.011s
It appears as if sqlldr times out waiting for a locked resource after round about 30 seconds, regardless of ddl_lock_timeout.
And this is the end of the story if you aren’t on 12.2 or later. In the next post I’ll show you how you can work around this problem with more current releases.