关于这个问题,我在Google和百度里找过一些文章,但是都是处理如何重新启动数据库的问题,比如:
startup force
然而我的问题是在tomcat每次重启后不久,在java程序通过JDBC驱动调用oracle时才出现的,没有进程或程序去关闭oracle,但是却出现了下面的错误,以下是oracle的emoms.log日志中的片断:
2009-09-03 13:54:46,437 [NotificationMgrThread] ERROR jdbc.ConnectionWrapper _applySessionParams.2980 - SQLException message: ORA-01089: 正在执行立即关闭 - 不允许进行任何操作java.sql.SQLException: ORA-01089: 正在执行立即关闭 - 不允许进行任何操作        at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:111)
        at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:330)
        at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:287)
        at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:742)
        at oracle.jdbc.driver.T4CCallableStatement.doOall8(T4CCallableStatement.java:211)
        at oracle.jdbc.driver.T4CCallableStatement.executeForRows(T4CCallableStatement.java:950)
        at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1252)
        at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3290)
        at oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3334)
        at oracle.sysman.util.jdbc.ConnectionWrapper._applySessionParams(ConnectionWrapper.java:2971)
        at oracle.sysman.util.jdbc.ConnectionWrapper.<init>(ConnectionWrapper.java:181)
        at oracle.sysman.emSDK.svc.conn.FGAConnection.<init>(FGAConnection.java:115)
        at oracle.sysman.emSDK.svc.conn.FGAConnectionCache.getFGAConnection(FGAConnectionCache.java:192)
        at oracle.sysman.emSDK.svc.conn.ConnectionService.getSystemConnection(ConnectionService.java:683)
        at oracle.sysman.emdrep.notification.NotificationMgr.getConnection(NotificationMgr.java:252)
        at oracle.sysman.emdrep.notification.NotificationMgr.resetConnection(NotificationMgr.java:298)
        at oracle.sysman.emdrep.notification.NotificationMgr.run(NotificationMgr.java:1190)
出现以上的错误是什么原因呢?怎么来解决这个问题?大家请帮帮忙,谢谢先!

解决方案 »

  1.   

    那你的数据库是真的在关闭吗?应该还有其他的可跟踪的信息的,比如alert.log, 那些trc文件
      

  2.   

    从昨天出错到目前的alert的日志内容如下:
    Thu Sep 03 12:18:33 2009
    Memory Notification: Library Cache Object loaded into SGA
    Heap size 2278K exceeds notification threshold (2048K)
    Details in trace file d:\oracle\product\10.2.0\admin\orcl\udump\orcl_ora_1476.trc
    KGL object name :XDB.XDZynXpO5DTv2jNMI2jLTZZA== ksdpec: called for event 13740 prior to event group initialization
    Starting up ORACLE RDBMS Version: 10.2.0.1.0.
    System parameters with non-default values:
      processes                = 150
      __shared_pool_size       = 201326592
      __large_pool_size        = 4194304
      __java_pool_size         = 8388608
      __streams_pool_size      = 0
      spfile                   = D:\ORACLE\PRODUCT\10.2.0\DB_1\DBS\SPFILEORCL.ORA
      sga_target               = 612368384
      control_files            = D:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\CONTROL01.CTL, D:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\CONTROL02.CTL, D:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\CONTROL03.CTL
      db_block_size            = 8192
      __db_cache_size          = 390070272
      compatible               = 10.2.0.1.0
      db_file_multiblock_read_count= 16
      db_recovery_file_dest    = D:\oracle\product\10.2.0/flash_recovery_area
      db_recovery_file_dest_size= 2147483648
      undo_management          = AUTO
      undo_tablespace          = UNDOTBS1
      remote_login_passwordfile= EXCLUSIVE
      db_domain                = 
      dispatchers              = (PROTOCOL=TCP) (SERVICE=orclXDB)
      job_queue_processes      = 10
      audit_file_dest          = D:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\ADUMP
      background_dump_dest     = D:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\BDUMP
      user_dump_dest           = D:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\UDUMP
      core_dump_dest           = D:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\CDUMP
      db_name                  = orcl
      open_cursors             = 300
      pga_aggregate_target     = 203423744
    MMAN started with pid=4, OS id=2984
    DBW0 started with pid=5, OS id=2988
    LGWR started with pid=6, OS id=2992
    CKPT started with pid=7, OS id=3000
    SMON started with pid=8, OS id=3004
    RECO started with pid=9, OS id=3008
    CJQ0 started with pid=10, OS id=3012
    MMON started with pid=11, OS id=3016
    MMNL started with pid=12, OS id=3020
    Thu Sep 03 12:22:34 2009
    starting up 1 dispatcher(s) for network address '(ADDRESS=(PARTIAL=YES)(PROTOCOL=TCP))'...
    starting up 1 shared server(s) ...
    Thu Sep 03 12:22:34 2009
    alter database mount exclusive
    PSP0 started with pid=3, OS id=2964
    PMON started with pid=2, OS id=2960
    Setting recovery target incarnation to 2
    Thu Sep 03 12:22:38 2009
    Successful mount of redo thread 1, with mount id 1224403594
    Thu Sep 03 12:22:38 2009
    Database mounted in Exclusive Mode
    Completed: alter database mount exclusive
    Thu Sep 03 12:22:39 2009
    alter database open
    Thu Sep 03 12:22:39 2009
    Beginning crash recovery of 1 threads
     parallel recovery started with 7 processes
    Thu Sep 03 12:22:39 2009
    Started redo scan
    Thu Sep 03 12:22:39 2009
    Completed redo scan
     575 redo blocks read, 88 data blocks need recovery
    Thu Sep 03 12:22:39 2009
    Started redo application at
     Thread 1: logseq 523, block 13507
    Thu Sep 03 12:22:39 2009
    Recovery of Online Redo Log: Thread 1 Group 3 Seq 523 Reading mem 0
      Mem# 0 errs 0: D:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\REDO03.LOG
    Thu Sep 03 12:22:39 2009
    Completed redo application
    Thu Sep 03 12:22:39 2009
    Completed crash recovery at
     Thread 1: logseq 523, block 14082, scn 18607219
     88 data blocks read, 88 data blocks written, 575 redo blocks read
    Thu Sep 03 12:22:40 2009
    Thread 1 advanced to log sequence 524
    Thread 1 opened at log sequence 524
      Current log# 1 seq# 524 mem# 0: D:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\REDO01.LOG
    Successful open of redo thread 1
    Thu Sep 03 12:22:40 2009
    MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
    Thu Sep 03 12:22:40 2009
    SMON: enabling cache recovery
    Thu Sep 03 12:22:41 2009
    Successfully onlined Undo Tablespace 1.
    Thu Sep 03 12:22:41 2009
    SMON: enabling tx recovery
    Thu Sep 03 12:22:41 2009
    Database Characterset is ZHS16GBK
    replication_dependency_tracking turned off (no async multimaster replication found)
    Starting background process QMNC
    QMNC started with pid=22, OS id=3184
    Thu Sep 03 12:22:46 2009
    db_recovery_file_dest_size of 2048 MB is 0.00% used. This is a
    user-specified limit on the amount of space that will be used by this
    database for recovery-related files, and does not reflect the amount of
    space available in the underlying filesystem or ASM diskgroup.
    Thu Sep 03 12:22:46 2009
    Completed: alter database open
    Thu Sep 03 12:23:03 2009
    Memory Notification: Library Cache Object loaded into SGA
    Heap size 2204K exceeds notification threshold (2048K)
    KGL object name :XDB.XDbD/PLZ01TcHgNAgAIIegtw== Thu Sep 03 12:23:03 2009
    Memory Notification: Library Cache Object loaded into SGA
    Heap size 2102K exceeds notification threshold (2048K)
    Details in trace file d:\oracle\product\10.2.0\admin\orcl\udump\orcl_ora_3528.trc
    KGL object name :XDB.XDZynXpO5DTv2jNMI2jLTZZA== ksdpec: called for event 13740 prior to event group initialization
    Starting up ORACLE RDBMS Version: 10.2.0.1.0.
    System parameters with non-default values:
      processes                = 150
      __shared_pool_size       = 213909504
      __large_pool_size        = 4194304
      __java_pool_size         = 8388608
      __streams_pool_size      = 0
      spfile                   = D:\ORACLE\PRODUCT\10.2.0\DB_1\DBS\SPFILEORCL.ORA
      sga_target               = 612368384
      control_files            = D:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\CONTROL01.CTL, D:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\CONTROL02.CTL, D:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\CONTROL03.CTL
      db_block_size            = 8192
      __db_cache_size          = 377487360
      compatible               = 10.2.0.1.0
      db_file_multiblock_read_count= 16
      db_recovery_file_dest    = D:\oracle\product\10.2.0/flash_recovery_area
      db_recovery_file_dest_size= 2147483648
      undo_management          = AUTO
      undo_tablespace          = UNDOTBS1
      remote_login_passwordfile= EXCLUSIVE
      db_domain                = 
      dispatchers              = (PROTOCOL=TCP) (SERVICE=orclXDB)
      job_queue_processes      = 10
      audit_file_dest          = D:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\ADUMP
      background_dump_dest     = D:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\BDUMP
      user_dump_dest           = D:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\UDUMP
      core_dump_dest           = D:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\CDUMP
      db_name                  = orcl
      open_cursors             = 300
      pga_aggregate_target     = 203423744
    PMON started with pid=2, OS id=3008
    MMAN started with pid=4, OS id=3016
    DBW0 started with pid=5, OS id=3020
    LGWR started with pid=6, OS id=3024
    CKPT started with pid=7, OS id=3028
    SMON started with pid=8, OS id=3032
    RECO started with pid=9, OS id=3036
    CJQ0 started with pid=10, OS id=3040
    MMON started with pid=11, OS id=3048
    MMNL started with pid=12, OS id=3060
      

  3.   

    接着上面的:
    Thu Sep 03 13:52:02 2009
    starting up 1 dispatcher(s) for network address '(ADDRESS=(PARTIAL=YES)(PROTOCOL=TCP))'...
    starting up 1 shared server(s) ...
    Thu Sep 03 13:52:02 2009
    alter database mount exclusive
    PSP0 started with pid=3, OS id=3012
    Thu Sep 03 13:52:06 2009
    Setting recovery target incarnation to 2
    Thu Sep 03 13:52:06 2009
    Successful mount of redo thread 1, with mount id 1224366466
    Thu Sep 03 13:52:06 2009
    Database mounted in Exclusive Mode
    Completed: alter database mount exclusive
    Thu Sep 03 13:52:07 2009
    alter database open
    Thu Sep 03 13:52:07 2009
    Beginning crash recovery of 1 threads
     parallel recovery started with 7 processes
    Thu Sep 03 13:52:07 2009
    Started redo scan
    Thu Sep 03 13:52:07 2009
    Completed redo scan
     107 redo blocks read, 31 data blocks need recovery
    Thu Sep 03 13:52:07 2009
    Started redo application at
     Thread 1: logseq 524, block 11072
    Thu Sep 03 13:52:07 2009
    Recovery of Online Redo Log: Thread 1 Group 1 Seq 524 Reading mem 0
      Mem# 0 errs 0: D:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\REDO01.LOG
    Thu Sep 03 13:52:07 2009
    Completed redo application
    Thu Sep 03 13:52:07 2009
    Completed crash recovery at
     Thread 1: logseq 524, block 11179, scn 18633619
     31 data blocks read, 31 data blocks written, 107 redo blocks read
    Thu Sep 03 13:52:08 2009
    Thread 1 advanced to log sequence 525
    Thread 1 opened at log sequence 525
      Current log# 2 seq# 525 mem# 0: D:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\REDO02.LOG
    Successful open of redo thread 1
    Thu Sep 03 13:52:08 2009
    MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
    Thu Sep 03 13:52:08 2009
    SMON: enabling cache recovery
    Thu Sep 03 13:52:09 2009
    Successfully onlined Undo Tablespace 1.
    Thu Sep 03 13:52:09 2009
    SMON: enabling tx recovery
    Thu Sep 03 13:52:09 2009
    Database Characterset is ZHS16GBK
    replication_dependency_tracking turned off (no async multimaster replication found)
    Starting background process QMNC
    QMNC started with pid=23, OS id=3196
    Thu Sep 03 13:52:13 2009
    db_recovery_file_dest_size of 2048 MB is 0.00% used. This is a
    user-specified limit on the amount of space that will be used by this
    database for recovery-related files, and does not reflect the amount of
    space available in the underlying filesystem or ASM diskgroup.
    Thu Sep 03 13:52:13 2009
    Completed: alter database open
    Thu Sep 03 13:54:39 2009
    Starting background process EMN0
    EMN0 started with pid=28, OS id=2200
    Thu Sep 03 13:54:39 2009
    Shutting down instance: further logons disabled
    Thu Sep 03 13:54:41 2009
    Stopping background process QMNC
    Thu Sep 03 13:54:42 2009
    Stopping background process CJQ0
    Thu Sep 03 13:54:43 2009
    Stopping background process MMNL
    Thu Sep 03 13:54:44 2009
    Stopping background process MMON
    Thu Sep 03 13:54:45 2009
    Shutting down instance (immediate)
    License high water  = 17
    Thu Sep 03 13:54:45 2009
    Stopping Job queue slave processes
    Thu Sep 03 13:54:45 2009
    Job queue slave processes stopped
    All dispatchers and shared servers shutdown
    Thu Sep 03 13:54:55 2009
    alter database close normal
    Thu Sep 03 13:54:55 2009
    SMON: disabling tx recovery
    SMON: disabling cache recovery
    Thu Sep 03 13:54:55 2009
    Shutting down archive processes
    Archiving is disabled
    Archive process shutdown avoided: 0 active
    Thread 1 closed at log sequence 525
    Successful close of redo thread 1
    Thu Sep 03 13:54:55 2009
    Completed: alter database close normal
    Thu Sep 03 13:54:55 2009
    alter database dismount
    Completed: alter database dismount
    ARCH: Archival disabled due to shutdown: 1089
    Shutting down archive processes
    Archiving is disabled
    Archive process shutdown avoided: 0 active
    ARCH: Archival disabled due to shutdown: 1089
    Shutting down archive processes
    Archiving is disabled
    Archive process shutdown avoided: 0 active
    ksdpec: called for event 13740 prior to event group initialization
    Starting up ORACLE RDBMS Version: 10.2.0.1.0.
    System parameters with non-default values:
      processes                = 150
      __shared_pool_size       = 218103808
      __large_pool_size        = 4194304
      __java_pool_size         = 8388608
      __streams_pool_size      = 0
      spfile                   = D:\ORACLE\PRODUCT\10.2.0\DB_1\DBS\SPFILEORCL.ORA
      sga_target               = 612368384
      control_files            = D:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\CONTROL01.CTL, D:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\CONTROL02.CTL, D:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\CONTROL03.CTL
      db_block_size            = 8192
      __db_cache_size          = 373293056
      compatible               = 10.2.0.1.0
      db_file_multiblock_read_count= 16
      db_recovery_file_dest    = D:\oracle\product\10.2.0/flash_recovery_area
      db_recovery_file_dest_size= 2147483648
      undo_management          = AUTO
      undo_tablespace          = UNDOTBS1
      remote_login_passwordfile= EXCLUSIVE
      db_domain                = 
      dispatchers              = (PROTOCOL=TCP) (SERVICE=orclXDB)
      job_queue_processes      = 10
      audit_file_dest          = D:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\ADUMP
      background_dump_dest     = D:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\BDUMP
      user_dump_dest           = D:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\UDUMP
      core_dump_dest           = D:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\CDUMP
      db_name                  = orcl
      open_cursors             = 300
      pga_aggregate_target     = 203423744
    PMON started with pid=2, OS id=2576
    PSP0 started with pid=3, OS id=2532
    MMAN started with pid=4, OS id=2548
    DBW0 started with pid=5, OS id=2528
    LGWR started with pid=6, OS id=2560
    CKPT started with pid=7, OS id=2608
    SMON started with pid=8, OS id=2664
    RECO started with pid=9, OS id=2712
    CJQ0 started with pid=10, OS id=2656
    MMON started with pid=11, OS id=2612
    MMNL started with pid=12, OS id=2604
    Thu Sep 03 13:55:01 2009
    starting up 1 dispatcher(s) for network address '(ADDRESS=(PARTIAL=YES)(PROTOCOL=TCP))'...
    starting up 1 shared server(s) ...
    Thu Sep 03 13:55:01 2009
    alter database mount exclusive
    Thu Sep 03 13:55:05 2009
    Setting recovery target incarnation to 2
    Thu Sep 03 13:55:05 2009
    Successful mount of redo thread 1, with mount id 1224384821
    Thu Sep 03 13:55:05 2009
    Database mounted in Exclusive Mode
    Completed: alter database mount exclusive
    Thu Sep 03 13:55:05 2009
    alter database open
    Thu Sep 03 13:55:05 2009
    Thread 1 opened at log sequence 525
      Current log# 2 seq# 525 mem# 0: D:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\REDO02.LOG
    Successful open of redo thread 1
    Thu Sep 03 13:55:05 2009
    MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
    Thu Sep 03 13:55:05 2009
    SMON: enabling cache recovery
    Thu Sep 03 13:55:05 2009
    Successfully onlined Undo Tablespace 1.
    Thu Sep 03 13:55:05 2009
    SMON: enabling tx recovery
    Thu Sep 03 13:55:05 2009
    Database Characterset is ZHS16GBK
    replication_dependency_tracking turned off (no async multimaster replication found)
    Starting background process QMNC
    QMNC started with pid=16, OS id=2936
    Thu Sep 03 13:55:08 2009
    db_recovery_file_dest_size of 2048 MB is 0.00% used. This is a
    user-specified limit on the amount of space that will be used by this
    database for recovery-related files, and does not reflect the amount of
    space available in the underlying filesystem or ASM diskgroup.
    Thu Sep 03 13:55:08 2009
    Completed: alter database open
    Thu Sep 03 19:55:34 2009
    Memory Notification: Library Cache Object loaded into SGA
    Heap size 2251K exceeds notification threshold (2048K)
    KGL object name :XDB.XDbD/PLZ01TcHgNAgAIIegtw== Thu Sep 03 19:55:35 2009
    Memory Notification: Library Cache Object loaded into SGA
    Heap size 2232K exceeds notification threshold (2048K)
    Details in trace file d:\oracle\product\10.2.0\admin\orcl\udump\orcl_ora_4040.trc
    KGL object name :XDB.XDZynXpO5DTv2jNMI2jLTZZA== Thu Sep 03 22:00:25 2009
    Thread 1 advanced to log sequence 526
      Current log# 3 seq# 526 mem# 0: D:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\REDO03.LOG
    Fri Sep 04 07:22:41 2009
    Thread 1 advanced to log sequence 527
      Current log# 1 seq# 527 mem# 0: D:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\REDO01.LOG
      

  4.   

    上面的日志沒有什么異常的地方,
    看看listner.log的信息。你做的操作是什么操作,是不是比較耗時的操作。
      

  5.   

    有没有update游标的操作。看你的java的异常,好像有调用到CallableStatement,是不是有调用sp呀。
      

  6.   

    能不能把你调用的那段java代码贴上来看看。
      

  7.   

    我的问题解决了,是数据库的问题,我是没到那个时间点,oracle会进行备份,所以这时候系统运行就报上面错误。希望对LZ有帮助!
      

  8.   

    根据你的日志,我感觉是你的库在该时间还是有问题的,看下边2009-09-03 13:54:46,437 [NotificationMgrThread] ERROR jdbc.ConnectionWrapper _applySessionParams.2980 - SQLException message: ORA-01089: 正在执行立即关闭 - 不允许进行任何操作 java.sql.SQLException: ORA-01089: 正在执行立即关闭 - 不允许进行任何操作 
    -------------------------------------------------------------------------]Thu Sep 03 13:54:39 2009 
    Shutting down instance: further logons disabled 
    Thu Sep 03 13:54:41 2009 
    Stopping background process QMNC 
    Thu Sep 03 13:54:42 2009 
    Stopping background process CJQ0 
    Thu Sep 03 13:54:43 2009 
    Stopping background process MMNL 
    Thu Sep 03 13:54:44 2009 
    Stopping background process MMON 
    Thu Sep 03 13:54:45 2009 
    Shutting down instance (immediate) 
    License high water  = 17 
    Thu Sep 03 13:54:45 2009 
    Stopping Job queue slave processes 
    Thu Sep 03 13:54:45 2009 
    Job queue slave processes stopped 
    All dispatchers and shared servers shutdown 
    Thu Sep 03 13:54:55 2009 
    alter database close normal 
    Thu Sep 03 13:54:55 2009 
    SMON: disabling tx recovery 
    SMON: disabling cache recovery 
    Thu Sep 03 13:54:55 2009 
    Shutting down archive processes 
    Thu Sep 03 13:54:45 2009 
    Stopping Job queue slave processes 
    Thu Sep 03 13:54:45 2009 
    Job queue slave processes stopped 
    All dispatchers and shared servers shutdown 
    Thu Sep 03 13:54:55 2009 
    alter database close normal 
    有Job在这个时间?