Skip to Main Content

Oracle Database Discussions

Announcement

For appeals, questions and feedback about Oracle Forums, please email oracle-forums-moderators_us@oracle.com. Technical questions should be asked in the appropriate category. Thank you!

Issue opening database after crash-consistent snapshot with or without recovery

User_20ACPDec 23 2020

I'm having an issue opening a database after a crash-consistent snapshot. The scenario is:
1. Perform a incremental backup forever on the database, including the archive logs, controlfile and spfile. Immediately recover the incremental backup into the image file copy of the database, so that the image file is as up to date as possible

RMAN> set echo on; 
2> connect target * 
3> run { 
4>   configure controlfile autobackup on; 
5>   allocate channel c1 type disk format 'C:\oracle_backups_bat\backup\%U'; 
6>   backup as compressed backupset incremental level 1 for recover of copy with tag 'DB_INCR_BACKUP' database; 
7>   recover copy of database with tag 'DB_INCR_BACKUP'; 
8>   backup as compressed backupset tag 'DB_INCR_BACKUP' archivelog all not backed up; 
9>   release channel c1; 
10> } 
11> exit;

2. OS copy all the database files and backup backup files to another VM.
3. Prior to doing any restore/recovery on the other VM, check to see if the datafiles are consistent using the "scandatafiles.sql" script.

set serveroutput on
declare
 scn number(12) := 0;
 scnmax number(12) := 0;
begin
 for f in (select * from v$datafile) loop
  scn := dbms_backup_restore.scandatafile(f.file#);
  dbms_output.put_line('File ' || f.file# ||' absolute fuzzy scn = ' || scn);
  if scn > scnmax then scnmax := scn; end if;
 end loop;
 dbms_output.put_line('Minimum PITR SCN = ' || scnmax);
end;
/

The output from this script is:

SQL> @scandatafiles.sql
File 1 absolute fuzzy scnn = 0
File 2 absolute fuzzy scnn = 0
File 3 absolute fuzzy scnn = 0
File 4 absolute fuzzy scnn = 0
File 5 absolute fuzzy scnn = 0
File 6 absolute fuzzy scnn = 0
File 7 absolute fuzzy scnn = 0
File 8 absolute fuzzy scnn = 0
File 9 absolute fuzzy scnn = 0
File 10 absolute fuzzy scnn = 0
File 11 absolute fuzzy scnn = 0
File 12 absolute fuzzy scnn = 0
File 13 absolute fuzzy scnn = 0
File 14 absolute fuzzy scnn = 0
File 15 absolute fuzzy scnn = 0
Minimum PITR SCN = 0

According to a link that I'm not allowed to post (haven't "been around" long enough) this output implies that the database is consistent and doesn't require any recovery. However, when I attempt to open the database, I get the following:

SQL> alter database open;
alter database open
*
ERROR at line 1:
ORA-00314: log 3 of thread 1, expected sequence# 5304 doesn't match 5229
ORA-00312: online log 3 thread 1:
'C:\APP\ADMINISTRATOR\ORADATA\ORCL\REDO03.LOG'

At this point, I attempted to perform restore/recovery from the RMAN backup

C:\Users\Administrator>rman

Recovery Manager: Release 12.2.0.1.0 - Production on Wed Dec 23 10:58:32 2020

Copyright (c) 1982, 2017, Oracle and/or its affiliates. All rights recovered.

RMAN> connect target / ;

connected to target database: ORCL (DBID=1569463076, not open)

RMAN> shutdown immediate;

using target database control file instead of recovery catalog
database dismounted
Oracle instance shut down

RMAN> startup mount;

connected to target database (not started)
Oracle instance started
database mounted

Total System Global Area  1728053248 bytes

Fixed Size          8919776 bytes
Variable Size       1040188704 bytes
Database Buffers      671088640 bytes
Redo Buffers         7856128 bytes

RMAN> restore database;

Starting restore at 23-DEC-20
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=261 device type=DISK

skipping datafile 1; already restore to file C:\APP\ADMMINISTRATOR\ORADATA\ORCL\SYSTEM01.DBF
skipping datafile 2; already restore to file C:\APP\ADMMINISTRATOR\ORADATA\ORCL\PDBSEED\SYSTEM01.DBF
skipping datafile 3; already restore to file C:\APP\ADMMINISTRATOR\ORADATA\ORCL\SYSAUX01.DBF
skipping datafile 4; already restore to file C:\APP\ADMMINISTRATOR\ORADATA\ORCL\PDBSEED\SYSAUX01.DBF
skipping datafile 5; already restore to file C:\APP\ADMMINISTRATOR\ORADATA\ORCL\UNDOTBS01.DBF
skipping datafile 6; already restore to file C:\APP\ADMMINISTRATOR\ORADATA\ORCL\PDBSEED\UNDOTBS01.DBF
skipping datafile 7; already restore to file C:\APP\ADMMINISTRATOR\ORADATA\ORCL\USERS01.DBF
skipping datafile 8; already restore to file C:\APP\ADMMINISTRATOR\ORADATA\ORCL\ORCLPDB\SYSTEM01.DBF
skipping datafile 9; already restore to file C:\APP\ADMMINISTRATOR\ORADATA\ORCL\ORCLPDB\SYSAUX01.DBF
skipping datafile 10; already restore to file C:\APP\ADMMINISTRATOR\ORADATA\ORCL\ORCLPDB\UNDOTBS01.DBF
skipping datafile 11; already restore to file C:\APP\ADMMINISTRATOR\ORADATA\ORCL\ORCLPDB\USERS01.DBF
skipping datafile 12; already restore to file C:\APP\ADMMINISTRATOR\ORADATA\ORCL\PERSONS\SYSTEM01.DBF
skipping datafile 13; already restore to file C:\APP\ADMMINISTRATOR\ORADATA\ORCL\PERSONS\SYSAUX01.DBF
skipping datafile 14; already restore to file C:\APP\ADMMINISTRATOR\ORADATA\ORCL\PERSONS\UNDOTBS01.DBF
skipping datafile 15; already restore to file C:\APP\ADMMINISTRATOR\ORADATA\ORCL\PERSONS\USERS01.DBF
restore not done; all files read only, offline, excluded, or already restored
Finished restore at 23-DEC-20

RMAN> recover database;

Starting recover at 23-DEC-20
using channel ORA_DISK_1

starting media recovery

archived log for thread 1 with sequence 5304 is already on disk as file C:\APP\ORACLE\ORADATA\ARCH\ARCH0000005304_1041682343.0001
archived log file name=C:\APP\ORACLE\ORADATA\ARCH\ARCH0000005304_1041682343.0001 thread=1 sequence=5304
RMAN-00571: ============================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ================
RMAN-00571: ============================================================
RMAN-03002: failure or recover command at 12/23/2020 11:01:21
ORA-00283: recovery session canceled due to errors
RMAN-11003: failure during parse/execution of SQL statement: alter database recover logfile 'C:\APP\ORACLE\ORADATA\ARCH\ARCH0000005304_1041682343.0001'
ORA-00283: recovery session canceled due to errors
ORA-00314: log 1 of thread 1, expected sequence# 5305 doesn't match 5227
ORA-00312: online log 1 thread 1:
'C:\APP\ADMINISTRATOR\ORADATA\ORCL\REDO01.LOG'

At this point, I'm able to perform a 'recover database until cancel' to enable the database to open:

SQL> recover database until cancel;
ORA-00279: change 25029243 generated at 12/23/2020 10:00:32 needed for thread 1
ORA-00289: suggestion :
C:\APP\ORACLE\ORADATA\ARCH\ARCH0000005304_1041682343.0001
ORA-00280: change 25029243 for thread 1 is in sequence #5304

Specify log: (<RET>=suggested | filename | AUTO | CANCEL)
auto
ORA-00279: change 25029345 generated at 12/23/2020 10:02:23 needed for thread 1
ORA-00289: suggestion :
C:\APP\ORACLE\ORADATA\ARCH\ARCH0000005305_1041682343.0001
ORA-00280: change 25029345 for thread 1 is in sequence #5305
ORA-00278: log file 'C:\APP\ORACLE\ORADATA\ARCH\ARCH0000005304_1041682343.0001' no longer needed for this recovery


ORA-00308: cannot open archived log
'C:\APP\ORACLE\ORADATA\ARCH\ARCH0000005305_1041682343.0001'
ORA-27041: unabled to open file
OSD-04002: unabled to open file
O/S-Error: (OS 2) The system cannot find the file specified.


SQL> alter database open resetlogs;

Database altered.

SQL>

Note that the file that can't be found:
'C:\APP\ORACLE\ORADATA\ARCH\ARCH0000005305_1041682343.0001'
does not exist on the original server.
Any help understanding why the database can't be opened prior to recovery or "fully" recovered would be greatly appreciated. There must be something fundamentally wrong in what I'm attempting to do?
Thanks,
Steve

Comments

Gary Graham-Oracle

Keep in mind you can always get a full thread dump from Java applications even when not running them from a command line console with an adequate buffer size.  Use the following Java utilities from the command line...

1. jps -l, which lists the application process ids of any running Java applications

2. jstack <pid>

And if that command line console's buffer is too small, just redirect the jstack output to a file...

3. jstack <pid> > mydump.log

2725878

Thanks for the instructions, I was wondering how I would. Here's the entire stack trace, thank you.

2014-08-04 15:11:31

Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.55-b03 mixed mode):

"deadlock-scanner" prio=6 tid=0x00000000112a4000 nid=0x2248 waiting on condition [0x000000001336f000]

   java.lang.Thread.State: WAITING (parking)

  at sun.misc.Unsafe.park(Native Method)

  - parking to wait for  <0x00000000f6c2abb8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)

  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)

  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)

  at java.util.concurrent.DelayQueue.take(DelayQueue.java:209)

  at java.util.concurrent.DelayQueue.take(DelayQueue.java:68)

  at oracle.javatools.buffer.JdkReadWriteLockImplementation$DeadlockScanner.run(JdkReadWriteLockImplementation.java:332)

   Locked ownable synchronizers:

  - None

"Calculating breadcrumbs for PUBLIC_INT Body" prio=6 tid=0x0000000010ff4000 nid=0x22cc waiting on condition [0x0000000014b0f000]

   java.lang.Thread.State: WAITING (parking)

  at sun.misc.Unsafe.park(Native Method)

  - parking to wait for  <0x00000000f5e22f00> (a oracle.dbtools.raptor.backgroundTask.RaptorTaskManager$RaptorFutureTask)

  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)

  at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:425)

  at java.util.concurrent.FutureTask.get(FutureTask.java:187)

  at oracle.dbtools.raptor.backgroundTask.RaptorTaskManager$IdeTaskTracker.run(RaptorTaskManager.java:594)

  at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:

  - None

"DBRequestProcessorFactory_Timer" daemon prio=6 tid=0x00000000112a0000 nid=0x21e0 in Object.wait() [0x000000001169f000]

   java.lang.Thread.State: WAITING (on object monitor)

  at java.lang.Object.wait(Native Method)

  - waiting on <0x00000000d3a80ce0> (a java.util.TaskQueue)

  at java.lang.Object.wait(Object.java:503)

  at java.util.TimerThread.mainLoop(Timer.java:526)

  - locked <0x00000000d3a80ce0> (a java.util.TaskQueue)

  at java.util.TimerThread.run(Timer.java:505)

   Locked ownable synchronizers:

  - None

"Background Parser" prio=6 tid=0x0000000010ff0000 nid=0x1294 waiting on condition [0x000000001490f000]

   java.lang.Thread.State: TIMED_WAITING (sleeping)

  at java.lang.Thread.sleep(Native Method)

  at oracle.dbtools.raptor.plsql.BackgroundParser$1.construct(BackgroundParser.java:142)

  at oracle.dbtools.raptor.utils.NamedSwingWorker$2.run(NamedSwingWorker.java:115)

  at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:

  - None

"SwingWorker-pool-6-thread-1" daemon prio=6 tid=0x0000000010fef800 nid=0x1710 waiting on condition [0x000000001480f000]

   java.lang.Thread.State: WAITING (parking)

  at sun.misc.Unsafe.park(Native Method)

  - parking to wait for  <0x00000000d39c9d30> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)

  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)

  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)

  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)

  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)

  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)

  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

  at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:

  - None

"pool-4-thread-1" prio=6 tid=0x00000000112a1800 nid=0x20cc waiting on condition [0x0000000012e6f000]

   java.lang.Thread.State: TIMED_WAITING (parking)

  at sun.misc.Unsafe.park(Native Method)

  - parking to wait for  <0x00000000d39cc6b0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)

  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)

  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)

  at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090)

  at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807)

  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)

  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)

  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

  at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:

  - None

"AsynchronousIdeActionHandler_TI" daemon prio=2 tid=0x000000000af3f000 nid=0x1fe0 runnable [0x000000001033d000]

   java.lang.Thread.State: RUNNABLE

  at java.net.SocketInputStream.socketRead0(Native Method)

  at java.net.SocketInputStream.read(SocketInputStream.java:152)

  at java.net.SocketInputStream.read(SocketInputStream.java:122)

  at oracle.net.ns.Packet.receive(Packet.java:300)

  at oracle.net.ns.DataPacket.receive(DataPacket.java:106)

  at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:315)

  at oracle.net.ns.NetInputStream.read(NetInputStream.java:260)

  at oracle.net.ns.NetInputStream.read(NetInputStream.java:185)

  at oracle.net.ns.NetInputStream.read(NetInputStream.java:102)

  at oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:124)

  at oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:80)

  at oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1137)

  at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:290)

  at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:192)

  at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:531)

  at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:193)

  at oracle.jdbc.driver.T4CStatement.executeForRows(T4CStatement.java:1033)

  at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1329)

  at oracle.jdbc.driver.OracleStatement.executeInternal(OracleStatement.java:1909)

  at oracle.jdbc.driver.OracleStatement.execute(OracleStatement.java:1871)

  - locked <0x00000000d2599e10> (a oracle.jdbc.driver.T4CConnection)

  at oracle.jdbc.driver.OracleStatementWrapper.execute(OracleStatementWrapper.java:318)

  at oracle.dbtools.raptor.navigator.plsql.OraPls.plsSubmit(OraPls.java:274)

  at oracle.dbtools.raptor.navigator.plsql.PlSqlTranslator.translate(PlSqlTranslator.java:55)

  at oracle.dbtools.raptor.navigator.plsql.PlSqlNode.saveImpl(PlSqlNode.java:371)

  at oracle.ide.model.Node.save(Node.java:1195)

  at oracle.ide.cmd.SaveCommand._saveNode(SaveCommand.java:176)

  at oracle.ide.cmd.SaveCommand.doit(SaveCommand.java:66)

  at oracle.ide.controller.CommandProcessor.invoke(CommandProcessor.java:377)

  at oracle.ide.IdeController.handleSaveCommand(IdeController.java:421)

  at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

  at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)

  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

  at java.lang.reflect.Method.invoke(Method.java:606)

  at oracle.ide.controller.AnnotatedController$CmdInfo.invoke(AnnotatedController.java:255)

  at oracle.ide.controller.AnnotatedController$CmdInfo.handle(AnnotatedController.java:241)

  at oracle.ide.controller.AnnotatedController.handleEvent(AnnotatedController.java:72)

  at oracle.ide.controller.AsynchronousController.handleEvent(AsynchronousController.java:161)

  at oracle.ide.controller.AsynchronousController$AcRunnable.run(AsynchronousController.java:555)

  at org.openide.util.RequestProcessor$Task.run(RequestProcessor.java:1432)

  at org.openide.util.RequestProcessor$Processor.run(RequestProcessor.java:2044)

   Locked ownable synchronizers:

  - <0x00000000d2e52a18> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

  - <0x00000000d351a7e8> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)

"status-0" prio=2 tid=0x00000000112a5800 nid=0x1ef0 waiting on condition [0x000000001470f000]

   java.lang.Thread.State: WAITING (parking)

  at sun.misc.Unsafe.park(Native Method)

  - parking to wait for  <0x00000000d353a598> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)

  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)

  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)

  at java.util.concurrent.DelayQueue.take(DelayQueue.java:209)

  at oracle.ide.status.StatusExecutor$StatusQueue.take(StatusExecutor.java:338)

  at oracle.ide.status.StatusExecutor$StatusQueue.take(StatusExecutor.java:300)

  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)

  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)

  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

  at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:

  - None

"WeakDataReference polling" prio=2 tid=0x00000000112a4800 nid=0x215c in Object.wait() [0x000000001450f000]

   java.lang.Thread.State: WAITING (on object monitor)

  at java.lang.Object.wait(Native Method)

  - waiting on <0x00000000d3241538> (a java.lang.ref.ReferenceQueue$Lock)

  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)

  - locked <0x00000000d3241538> (a java.lang.ref.ReferenceQueue$Lock)

  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)

  at oracle.ide.util.WeakDataReference$Cleaner.run(WeakDataReference.java:88)

  at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:

  - None

"Background Parser" prio=6 tid=0x00000000112a2800 nid=0x2180 waiting on condition [0x0000000012d6f000]

   java.lang.Thread.State: TIMED_WAITING (sleeping)

  at java.lang.Thread.sleep(Native Method)

  at oracle.dbtools.raptor.plsql.BackgroundParser$1.construct(BackgroundParser.java:142)

  at oracle.dbtools.raptor.utils.NamedSwingWorker$2.run(NamedSwingWorker.java:115)

  at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:

  - None

"TextBufferScavenger" prio=6 tid=0x000000000af43800 nid=0x1ef4 in Object.wait() [0x000000001146f000]

   java.lang.Thread.State: WAITING (on object monitor)

  at java.lang.Object.wait(Native Method)

  - waiting on <0x00000000d2c7c888> (a java.lang.ref.ReferenceQueue$Lock)

  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)

  - locked <0x00000000d2c7c888> (a java.lang.ref.ReferenceQueue$Lock)

  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)

  at oracle.ide.model.FacadeBufferReference$PollingThread.run(FacadeBufferReference.java:145)

   Locked ownable synchronizers:

  - None

"IconOverlayTracker Timer: null-jdbcNodeInfoType" prio=6 tid=0x00000000112a1000 nid=0x2330 in Object.wait() [0x000000001460f000]

   java.lang.Thread.State: WAITING (on object monitor)

  at java.lang.Object.wait(Native Method)

  - waiting on <0x00000000d2030d08> (a java.util.TaskQueue)

  at java.lang.Object.wait(Object.java:503)

  at java.util.TimerThread.mainLoop(Timer.java:526)

  - locked <0x00000000d2030d08> (a java.util.TaskQueue)

  at java.util.TimerThread.run(Timer.java:505)

   Locked ownable synchronizers:

  - None

"Timer-0" prio=6 tid=0x0000000010ff3000 nid=0x2050 in Object.wait() [0x000000001326f000]

   java.lang.Thread.State: WAITING (on object monitor)

  at java.lang.Object.wait(Native Method)

  - waiting on <0x00000000d26818d8> (a java.util.TaskQueue)

  at java.lang.Object.wait(Object.java:503)

  at java.util.TimerThread.mainLoop(Timer.java:526)

  - locked <0x00000000d26818d8> (a java.util.TaskQueue)

  at java.util.TimerThread.run(Timer.java:505)

   Locked ownable synchronizers:

  - None

"WaitCursor-Timer" prio=6 tid=0x0000000010ff1000 nid=0x2218 in Object.wait() [0x000000001316f000]

   java.lang.Thread.State: WAITING (on object monitor)

  at java.lang.Object.wait(Native Method)

  - waiting on <0x00000000d2681c98> (a java.util.TaskQueue)

  at java.lang.Object.wait(Object.java:503)

  at java.util.TimerThread.mainLoop(Timer.java:526)

  - locked <0x00000000d2681c98> (a java.util.TaskQueue)

  at java.util.TimerThread.run(Timer.java:505)

   Locked ownable synchronizers:

  - None

"pool-3-thread-1" prio=6 tid=0x0000000010ff2800 nid=0x20d8 waiting for monitor entry [0x000000001306e000]

   java.lang.Thread.State: BLOCKED (on object monitor)

  at oracle.javatools.db.execute.ConnectionWrapper$SQLCallable.callImpl(ConnectionWrapper.java:183)

  - waiting to lock <0x00000000d2599e10> (a oracle.jdbc.driver.T4CConnection)

  at oracle.javatools.db.execute.ConnectionWrapper$SQLCallable.access$000(ConnectionWrapper.java:176)

  at oracle.javatools.db.execute.ConnectionWrapper.call(ConnectionWrapper.java:124)

  at oracle.javatools.db.execute.ConnectionWrapper.call(ConnectionWrapper.java:115)

  at oracle.javatools.db.execute.ConnectionWrapper.run(ConnectionWrapper.java:100)

  at oracle.javatools.db.execute.QueryWrapper$QueryExecutionRunnable.runImpl(QueryWrapper.java:444)

  at oracle.javatools.db.execute.StatementWrapper$ExecutionRunnable.run(StatementWrapper.java:822)

  - locked <0x00000000f6836940> (a oracle.javatools.db.execute.QueryWrapper$QueryExecutionRunnable)

  at oracle.ideimpl.db.ProgressBarExecutionWrapper.runAndLog(ProgressBarExecutionWrapper.java:137)

  at oracle.ideimpl.db.ProgressBarExecutionWrapper.execute(ProgressBarExecutionWrapper.java:129)

  at oracle.javatools.db.execute.StatementWrapper$ExecutionProxy.doExecute(StatementWrapper.java:777)

  at oracle.javatools.db.execute.StatementWrapper$ExecutionProxy.access$300(StatementWrapper.java:715)

  at oracle.javatools.db.execute.StatementWrapper.doExecute(StatementWrapper.java:368)

  at oracle.javatools.db.execute.QueryWrapper.executeQuery(QueryWrapper.java:260)

  at oracle.javatools.db.execute.QueryWrapper.executeQuery(QueryWrapper.java:345)

  at oracle.javatools.db.dictionary.DictionaryDatabase.getExternalTimestampByID(DictionaryDatabase.java:709)

  at oracle.javatools.db.dictionary.DictionaryDatabase.getExternalTimestampImpl(DictionaryDatabase.java:575)

  at oracle.javatools.db.AbstractDBObjectProvider.getExternalTimestamp(AbstractDBObjectProvider.java:1910)

  at oracle.javatools.db.AbstractDBObjectProvider.resolveIDImpl(AbstractDBObjectProvider.java:1369)

  at oracle.javatools.db.AbstractDBObjectProvider.resolveID(AbstractDBObjectProvider.java:1324)

  at oracle.javatools.db.BaseObjectID.resolveFromProvider(BaseObjectID.java:210)

  at oracle.javatools.db.IdentifierBasedID.resolveID(IdentifierBasedID.java:228)

  at oracle.javatools.db.AbstractDBObjectBuilder.checkTimestamp(AbstractDBObjectBuilder.java:264)

  at oracle.javatools.db.AbstractDBObjectBuilder.fillInObjectComponent(AbstractDBObjectBuilder.java:556)

  at oracle.javatools.db.AbstractDBObjectBuilder.buildObjectComponent(AbstractDBObjectBuilder.java:517)

  at oracle.javatools.db.AbstractDBObjectBuilder.buildObjectComponent(AbstractDBObjectBuilder.java:38)

  at oracle.javatools.db.AbstractBuildableObject$BuildablePropertySupport.buildImplWhileLocked(AbstractBuildableObject.java:697)

  at oracle.javatools.db.AbstractBuildableObject$BuildablePropertySupport.access$1100(AbstractBuildableObject.java:282)

  at oracle.javatools.db.AbstractBuildableObject$BuildablePropertySupport$1.run(AbstractBuildableObject.java:647)

  at oracle.javatools.db.AbstractDBObject.invokeCompoundChange(AbstractDBObject.java:154)

  at oracle.javatools.db.AbstractBuildableObject$BuildablePropertySupport.runUnderPropertyLock(AbstractBuildableObject.java:365)

  at oracle.javatools.db.AbstractBuildableObject$BuildablePropertySupport.buildImpl(AbstractBuildableObject.java:659)

  at oracle.javatools.db.AbstractBuildableObject$BuildablePropertySupport.checkBuiltEx(AbstractBuildableObject.java:622)

  at oracle.javatools.db.AbstractBuildableObject$BuildablePropertySupport.checkBuilt(AbstractBuildableObject.java:503)

  at oracle.javatools.db.AbstractBuildableObject$LazyPropertiesMap.get(AbstractBuildableObject.java:1167)

  at oracle.javatools.db.AbstractDBObject.getProperty(AbstractDBObject.java:586)

  at oracle.javatools.db.plsql.PlSqlSchemaObject.getSource(PlSqlSchemaObject.java:27)

  at oracle.javatools.db.plsql.PlSqlInterrogatorFactory.getInterrogator(PlSqlInterrogatorFactory.java:54)

  at oracle.javatools.db.plsql.PlSqlInterrogatorFactory.getInterrogator(PlSqlInterrogatorFactory.java:31)

  at oracle.ideimpl.db.ceditor.PlSqlBreadcrumbsPlugin.updateBreadCrumbs(PlSqlBreadcrumbsPlugin.java:149)

  at oracle.ideimpl.db.ceditor.PlSqlBreadcrumbsPlugin.access$200(PlSqlBreadcrumbsPlugin.java:41)

  at oracle.ideimpl.db.ceditor.PlSqlBreadcrumbsPlugin$1.doWork(PlSqlBreadcrumbsPlugin.java:124)

  at oracle.ide.db.execute.DBRequestProcessor$DBRunnable.run(DBRequestProcessor.java:471)

  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)

  at java.util.concurrent.FutureTask.run(FutureTask.java:262)

  at oracle.jdevimpl.db.execute.DBRequestProcessorImpl$1.doWork(DBRequestProcessorImpl.java:96)

  at oracle.dbtools.raptor.backgroundTask.RaptorTask.call(RaptorTask.java:193)

  at java.util.concurrent.FutureTask.run(FutureTask.java:262)

  at oracle.dbtools.raptor.backgroundTask.RaptorTaskManager$RaptorFutureTask.run(RaptorTaskManager.java:554)

  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)

  at java.util.concurrent.FutureTask.run(FutureTask.java:262)

  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)

  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

  at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:

  - <0x00000000f60b3f30> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

  - <0x00000000d25989c0> (a java.util.concurrent.ThreadPoolExecutor$Worker)

"Scheduler" daemon prio=6 tid=0x0000000010ff1800 nid=0x1db0 in Object.wait() [0x0000000012f6f000]

   java.lang.Thread.State: WAITING (on object monitor)

  at java.lang.Object.wait(Native Method)

  - waiting on <0x00000000d25967a8> (a oracle.dbtools.raptor.backgroundTask.TaskLinkedList)

  at java.lang.Object.wait(Object.java:503)

  at oracle.dbtools.raptor.backgroundTask.TaskLinkedList.takeNextTask(TaskLinkedList.java:47)

  - locked <0x00000000d25967a8> (a oracle.dbtools.raptor.backgroundTask.TaskLinkedList)

  at oracle.dbtools.raptor.backgroundTask.RaptorTaskManager$SchedulerThread.run(RaptorTaskManager.java:479)

   Locked ownable synchronizers:

  - None

"Thread-8" daemon prio=6 tid=0x0000000010fee800 nid=0x22c0 in Object.wait() [0x0000000012c6f000]

   java.lang.Thread.State: WAITING (on object monitor)

  at java.lang.Object.wait(Native Method)

  - waiting on <0x00000000cf0d1500> (a java.util.LinkedList)

  at java.lang.Object.wait(Object.java:503)

  at java.util.prefs.AbstractPreferences$EventDispatchThread.run(AbstractPreferences.java:1476)

  - locked <0x00000000cf0d1500> (a java.util.LinkedList)

   Locked ownable synchronizers:

  - None

"ChangeSetService" daemon prio=2 tid=0x0000000010fed000 nid=0x2098 in Object.wait() [0x0000000012a6f000]

   java.lang.Thread.State: WAITING (on object monitor)

  at java.lang.Object.wait(Native Method)

  - waiting on <0x00000000d1bc3750> (a oracle.jdevimpl.vcs.changeset.ChangeSetService)

  at java.lang.Object.wait(Object.java:503)

  at oracle.jdevimpl.vcs.changeset.ChangeSetService.awaitEvents(ChangeSetService.java:131)

  - locked <0x00000000d1bc3750> (a oracle.jdevimpl.vcs.changeset.ChangeSetService)

  at oracle.jdevimpl.vcs.changeset.ChangeSetService.eventLoop(ChangeSetService.java:152)

  at oracle.jdevimpl.vcs.changeset.ChangeSetService.access$000(ChangeSetService.java:60)

  at oracle.jdevimpl.vcs.changeset.ChangeSetService$1.run(ChangeSetService.java:99)

  at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:

  - None

"Log Poller" prio=2 tid=0x000000000af43000 nid=0x2208 waiting on condition [0x000000001189f000]

   java.lang.Thread.State: WAITING (parking)

  at sun.misc.Unsafe.park(Native Method)

  - parking to wait for  <0x00000000d16848e8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)

  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)

  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)

  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)

  at oracle.ide.log.QueuedLoggingHandler.take(QueuedLoggingHandler.java:60)

  at oracle.ideimpl.log.TabbedLogManager$4.run(TabbedLogManager.java:321)

  at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:

  - None

"JarIndex Timer" daemon prio=6 tid=0x000000000af40800 nid=0x2234 in Object.wait() [0x000000001159f000]

   java.lang.Thread.State: TIMED_WAITING (on object monitor)

  at java.lang.Object.wait(Native Method)

  - waiting on <0x00000000cf059960> (a java.util.TaskQueue)

  at java.util.TimerThread.mainLoop(Timer.java:552)

  - locked <0x00000000cf059960> (a java.util.TaskQueue)

  at java.util.TimerThread.run(Timer.java:505)

   Locked ownable synchronizers:

  - None

"TimedCache-Timer" daemon prio=6 tid=0x000000000af40000 nid=0x1aa8 in Object.wait() [0x000000001023f000]

   java.lang.Thread.State: WAITING (on object monitor)

  at java.lang.Object.wait(Native Method)

  - waiting on <0x00000000cf34aef0> (a java.util.TaskQueue)

  at java.lang.Object.wait(Object.java:503)

  at java.util.TimerThread.mainLoop(Timer.java:526)

  - locked <0x00000000cf34aef0> (a java.util.TaskQueue)

  at java.util.TimerThread.run(Timer.java:505)

   Locked ownable synchronizers:

  - None

"Framework Event Dispatcher" daemon prio=6 tid=0x000000000af3d800 nid=0x200c in Object.wait() [0x000000001003f000]

   java.lang.Thread.State: WAITING (on object monitor)

  at java.lang.Object.wait(Native Method)

  - waiting on <0x00000000ce4da5d8> (a org.eclipse.osgi.framework.eventmgr.EventManager$EventThread)

  at java.lang.Object.wait(Object.java:503)

  at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.getNextEvent(EventManager.java:400)

  - locked <0x00000000ce4da5d8> (a org.eclipse.osgi.framework.eventmgr.EventManager$EventThread)

  at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:336)

   Locked ownable synchronizers:

  - None

"State Data Manager" daemon prio=6 tid=0x000000000b26d000 nid=0x2060 waiting on condition [0x000000000ff3f000]

   java.lang.Thread.State: TIMED_WAITING (sleeping)

  at java.lang.Thread.sleep(Native Method)

  at org.eclipse.osgi.internal.baseadaptor.StateManager.run(StateManager.java:297)

  at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:

  - None

"Framework Active Thread" prio=6 tid=0x000000000aff7800 nid=0xf58 in Object.wait() [0x000000000fe3f000]

   java.lang.Thread.State: TIMED_WAITING (on object monitor)

  at java.lang.Object.wait(Native Method)

  - waiting on <0x00000000d00f6528> (a org.eclipse.osgi.framework.internal.core.Framework)

  at org.eclipse.osgi.framework.internal.core.Framework.run(Framework.java:1863)

  - locked <0x00000000d00f6528> (a org.eclipse.osgi.framework.internal.core.Framework)

  at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:

  - None

"Active Reference Queue Daemon" daemon prio=2 tid=0x000000000a47f000 nid=0xa2c in Object.wait() [0x000000000b72f000]

   java.lang.Thread.State: TIMED_WAITING (on object monitor)

  at java.lang.Object.wait(Native Method)

  - waiting on <0x00000000d0296c10> (a java.lang.ref.ReferenceQueue$Lock)

  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)

  - locked <0x00000000d0296c10> (a java.lang.ref.ReferenceQueue$Lock)

  at org.openide.util.lookup.implspi.ActiveQueue$Daemon.run(ActiveQueue.java:180)

  - locked <0x00000000d0296c10> (a java.lang.ref.ReferenceQueue$Lock)

   Locked ownable synchronizers:

  - None

"TimerQueue" daemon prio=6 tid=0x000000000ac74000 nid=0x1af8 runnable [0x000000000b52f000]

   java.lang.Thread.State: TIMED_WAITING (parking)

  at sun.misc.Unsafe.park(Native Method)

  - parking to wait for  <0x00000000ce54fe90> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)

  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)

  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)

  at java.util.concurrent.DelayQueue.take(DelayQueue.java:220)

  at javax.swing.TimerQueue.run(TimerQueue.java:171)

  at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:

  - <0x00000000ce54feb8> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

"AWT-EventQueue-0" prio=6 tid=0x000000000a221000 nid=0x1ed8 waiting on condition [0x000000000ac2a000]

   java.lang.Thread.State: WAITING (parking)

  at sun.misc.Unsafe.park(Native Method)

  - parking to wait for  <0x00000000d351a7e8> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)

  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)

  at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)

  at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(AbstractQueuedSynchronizer.java:964)

  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1282)

  at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:731)

  at oracle.javatools.buffer.JdkReadWriteLockImplementation.lock(JdkReadWriteLockImplementation.java:202)

  at oracle.javatools.buffer.JdkReadWriteLockImplementation.readLock(JdkReadWriteLockImplementation.java:94)

  at oracle.javatools.buffer.ReadWriteLock.readLock(ReadWriteLock.java:192)

  at oracle.javatools.buffer.AbstractTextBuffer.readLock(AbstractTextBuffer.java:948)

  at oracle.javatools.buffer.ReadTextBufferDecorator.readLock(ReadTextBufferDecorator.java:126)

  at oracle.javatools.editor.BasicDocument.readLock(BasicDocument.java:442)

  at oracle.javatools.editor.folding.DefaultCodeFoldingModel.readLock(DefaultCodeFoldingModel.java:198)

  at oracle.javatools.editor.folding.CodeFoldingMargin.paintComponent(CodeFoldingMargin.java:855)

  at javax.swing.JComponent.paint(JComponent.java:1054)

  at javax.swing.JComponent.paintChildren(JComponent.java:887)

  - locked <0x00000000ce809790> (a java.awt.Component$AWTTreeLock)

  at javax.swing.JComponent.paint(JComponent.java:1063)

  at javax.swing.JComponent.paintChildren(JComponent.java:887)

  - locked <0x00000000ce809790> (a java.awt.

Does disabling Preferences->"Code Editor"->"Supports Gutter Navigation" together with  Preferences->"Code Editor"->"Display"->"Show Breadcrumbs" has any effect?

2725878

Still doing the same thing sadly.  I had "Supports Gutter Navigation" disabled already along with "sync spec and body." 

Vadim Tropashko-Oracle

When saving the file it also updates pl/sql module definition in the database. This is where the hang seem to occur. Then, breadcrumbs plugin tries to get connection for it purposes (lock 0x00000000d2599e10), it is blocked, but this thread block is irrelevant to the problem. I suspect that is you just copy and paste your create pl/sql module statement and run it from, say, sql*plus it will hang as well. Is it so?

Gary Graham-Oracle

In Tools > Preferences > Code Editor > Display, have you tried disabling Show Code Folding Margin?  Perhaps I'm misinterpreting it, but the main (EDT) thread is also waiting for a lock on a text buffer in document when trying to repaint the margin.

2725878

It still freezes after turning off folding margin.  Something I noticed was it works for about an hour when first booting up my laptop, it will freeze occasionally from saving or opening menus but it's inconsistent only for the first hour.  I forgot to add that it also freezes when I compile, which saves it too so it makes sense.  I also can't run or debug functions, sql developer doesn't freeze but my only options are to stop and pause, it never makes it to actually running code, not sure if that was relevant or not. 

Vadim, I'll try your suggestion later.  At the moment my higher up does not want me running it because of changes he's making and possible consequences.  But I'll keep it in mind for later, thanks for the suggestion

2725878
Answer

Finally figured it out, had to kill the session.  I'm embarressed to say that I didn't try looking at the user sessions. When I did I saw there was two for me, a normal one and the one that screwed everything up.  It took a few runs for anything to happen but in the end it worked, this link helped How to kill/terminate a session in Oracle

Marked as Answer by 2725878 · Sep 27 2020
User159239

I don't know if it is the same issue, today SQL Developer froze (black screen), but after opening a connection.

When looking at jstack, the main thread was BLOCKED on the same line as you :

  at oracle.javatools.db.execute.ConnectionWrapper$SQLCallable.callImpl(ConnectionWrapper.java:183)

(This is how I found this discussion)

The solution I found to fix the freeze was to shutdown the network on the computer (ipconfig /release on Windows).

Hope it will help someone.

1 - 9

Post Details

Added on Dec 23 2020
11 comments
1,356 views