Sunday, June 04, 2017

ALTER USER Hangs on row cache lock

I created the following UNIX shell script called loop1.ksh:

Oracle 11.1 > cat loop1.ksh
#!/bin/bash
export ORACLE_SID=PQEDPT1
export ORAENV_ASK=NO
. oraenv
sqlplus / as sysdba << eof
grant create session to andrew
identified by reid1
/
exit
eof
echo "User created"
./loop2.ksh > loop2.log1 &
./loop2.ksh > loop2.log2 &
./loop2.ksh > loop2.log3 &
./loop2.ksh > loop2.log4 &
./loop2.ksh > loop2.log5 &
./loop2.ksh > loop2.log6 &
./loop2.ksh > loop2.log7 &
./loop2.ksh > loop2.log8 &
./loop2.ksh > loop2.log9 &
./loop2.ksh > loop2.log10 &
Oracle 11.1 >

I ran it against an Oracle 11.1 database. It created a user called andrew with a password of reid1. It then ran another shell script called loop2.ksh 10 times. The ampersand at the end of each line made these 10 jobs run simultaneously in the background. Each run wrote its output to a different log file i.e. loop2.log1, loop2.log2 etc.

Here is the shell script loop2.ksh:

Oracle 11.1 > cat loop2.ksh
#!/bin/bash
export ORACLE_SID=PQEDPT1
export ORAENV_ASK=NO
. oraenv
for (( i=1; i <=100; i++ ))
do
echo 'i = '$i
sqlplus andrew/reid1 << eof
exit
eof
done
Oracle 11.1 >

It connected to and disconnected from the same database 100 times as user andrew. So I had 10 background jobs, each connecting to and disconnecting from the same database 100 times. Here is part of one of the output files:

DUM11.2 /export/home/oracle/andrew/hanging > cat loop2.log2|more
The Oracle base for ORACLE_HOME=/oracle/app/oracle/product/11.1.0 is /oracle/app/oracle/product
i = 1

SQL*Plus: Release 11.1.0.6.0 - Production on Tue Oct 13 18:26:40 2015

Copyright (c) 1982, 2007, Oracle.  All rights reserved.

Connected to:
Oracle Database 11g Enterprise Edition Release 11.1.0.6.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options

SQL> Disconnected from Oracle Database 11g Enterprise Edition Release 11.1.0.6.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
i = 2

SQL*Plus: Release 11.1.0.6.0 - Production on Tue Oct 13 18:26:41 2015

Copyright (c) 1982, 2007, Oracle.  All rights reserved.

Connected to:
Oracle Database 11g Enterprise Edition Release 11.1.0.6.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options

SQL> Disconnected from Oracle Database 11g Enterprise Edition Release 11.1.0.6.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
i = 3

SQL*Plus: Release 11.1.0.6.0 - Production on Tue Oct 13 18:26:41 2015

Copyright (c) 1982, 2007, Oracle.  All rights reserved.

Connected to:
Oracle Database 11g Enterprise Edition Release 11.1.0.6.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options

SQL> Disconnected from Oracle Database 11g Enterprise Edition Release 11.1.0.6.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
i = 4

SQL*Plus: Release 11.1.0.6.0 - Production on Tue Oct 13 18:26:41 2015

Copyright (c) 1982, 2007, Oracle.  All rights reserved.

Connected to:
Oracle Database 11g Enterprise Edition Release 11.1.0.6.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options

SQL> Disconnected from Oracle Database 11g Enterprise Edition Release 11.1.0.6.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
i = 5

SQL*Plus: Release 11.1.0.6.0 - Production on Tue Oct 13 18:26:42 2015

Copyright (c) 1982, 2007, Oracle.  All rights reserved.

While this was going on, I tried to change the password for user andrew in a separate SQL*Plus session. This took a long time. When it had finished, I checked the wait events and saw that it had been waiting on a row cache lock:

SQL> conn / as sysdba
Connected.
SQL> set timing on
SQL> alter user andrew identified by reid2
  2  /

User altered.

Elapsed: 00:00:24.94
SQL> set timing off
SQL> select event, time_waited/100
  2  from v$session_event
  3  where sid = (select distinct sid from v$mystat)
  4  and wait_class != 'Idle'
  5  /

EVENT                               TIME_WAITED/100
----------------------------------- ---------------
log file sync                                     0
row cache lock                                24.34
SQL*Net message to client                         0

SQL>

So if your ALTER USER statement hangs in this way, it could be due to other sessions trying to connect to the database again and again.

No comments: