> Because we had more and more data to insert, on Sept 10 we started parallel insert with 
> parallelism 16 (the same as CPU count). No problem till around Oct 20. Between 11pm and 
> 12, we get the error below (trc file attached) 
> 
> Wed Nov  4 00:18:51 2009
> >>> WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK! pid=61
> System State dumped to trace file /home/oracle/admin/ecis/bdump/ecis_p019_30075.trc
> Wed Nov  4 00:18:54 2009
> 
> The insert hangs till about 6am when it starts to insert again and everything is fine 
> then. This problem happens once in a while. 

You can read your system state dump file this way.

$ grep "row cache enqueue" tracefile
row cache enqueue: session: 0x1d8340650, mode: N, request: S
        row cache enqueue: count=1 session=0x1d8339b48 object=0x1da9da0f8, request=S
        row cache enqueue: count=1 session=0x1d73265f8 object=0x1da9da0f8, request=S
...
        row cache enqueue: count=1 session=0x1d731d020 object=0x1da9da0f8, mode=X

You see a bunch of request=S lines and one mode=X line, all on the same object (row cache enqueue object). Open the file and find the session that holds the X lock on row cache enqueue. That is, find the line with that mode=X for row cache enqueue, and go up a few pages to find the session, because the entries are ordered in indented format, with session as the parent of other things (row cache enqueue etc.). You'll see

Job Slave State Object
Slave ID: 1, Job ID: 8951
    ----------------------------------------
    SO: 0x1d731d020, type: 4, owner: 0x1d7255b00, flag: INIT/-/-/0x00
    (session) sid: 442 trans: 0x1d562e780, creator: 0x1d7255b00, flag: (48110041) USR/- BSY/-/-/-/-/-
...
              oct: 11, prv: 0, sql: 0x1d90da278, psql: 0x1dccdade8, user: 0/SYS
...
    O/S info: user: oracle, term: UNKNOWN, ospid: 10450, machine: serverc16
              program: oracle@serverc16 (J001)
    application name: DBMS_SCHEDULER, hash value=2478762354
    action name: AUTO_SPACE_ADVISOR_JOB, hash value=348111556
    waiting for 'Wait for shrink lock' blocking sess=0x(nil) seq=31697 wait_time=0 seconds since wait started=1674
                object_id=0, lock_mode=0, =0
    Dumping Session Wait History
     for 'Wait for shrink lock' count=1 wait_time=2076354
                object_id=0, lock_mode=0, =0

So you have the scheduler job that kicked in at that time to do a space advisory job. Command type (oct) 11 means alter index. Please stop it.


[Original discussion at http://www.itpub.net/thread-1232697-1-1.html]