SQLPlus Hangs

From: raghu <raghu_vnin_at_yahoo.com>
Date: Wed, 26 Dec 2007 03:38:10 -0800 (PST)
Message-ID: <ad00a53d-2507-4a6b-a1de-288c2b7d44f7@i29g2000prf.googlegroups.com>


When I enter the credentials in SQL Plus, it hangs. This happens both in the server machine (Oracle 10.2.0) and the clients. But I am able to login using the command prompt in the server. Tnsping works correctly. Nothing is logged in the alert log for the login attempt. Any ideas?

Here is an excerpt of the alert log:

Starting background process EMN0
EMN0 started with pid=134, OS id=3648
Wed Dec 26 11:56:33 2007
Shutting down instance: further logons disabled Wed Dec 26 11:56:33 2007
Stopping background process QMNC
Wed Dec 26 11:56:34 2007
Stopping background process CJQ0
Wed Dec 26 11:56:34 2007
Background process QMNC not dead after 150 seconds Wed Dec 26 11:56:34 2007
Killing background process QMNC
Wed Dec 26 11:56:34 2007
Stopping background process MMNL
Wed Dec 26 11:56:36 2007
Background process MMNL not dead after 10 seconds Wed Dec 26 11:56:36 2007
Killing background process MMNL
Wed Dec 26 11:56:36 2007
Stopping background process MMON
Wed Dec 26 11:56:37 2007
Background process MMON not dead after 30 seconds Wed Dec 26 11:56:37 2007
Killing background process MMON
Wed Dec 26 11:56:37 2007
Shutting down instance (immediate)
License high water mark = 5
Wed Dec 26 11:56:37 2007
Stopping Job queue slave processes
Wed Dec 26 11:56:37 2007
Job queue slave processes stopped
All dispatchers and shared servers shutdown Wed Dec 26 11:56:44 2007
ALTER DATABASE CLOSE NORMAL
Wed Dec 26 11:56:44 2007
SMON: disabling tx recovery
SMON: disabling cache recovery
Wed Dec 26 11:56:44 2007
SUCCESS: diskgroup ORAREDO was dismounted Shutting down archive processes
Archiving is disabled
Wed Dec 26 11:56:49 2007
ARCH shutting down
ARC1: Archival stopped
Wed Dec 26 11:56:54 2007
ARCH shutting down
ARC0: Archival stopped
Wed Dec 26 11:56:55 2007
Thread 1 closed at log sequence 15521
Successful close of redo thread 1
Wed Dec 26 11:56:59 2007
Completed: ALTER DATABASE CLOSE NORMAL
Wed Dec 26 11:56:59 2007
ALTER DATABASE DISMOUNT
Wed Dec 26 11:56:59 2007
SUCCESS: diskgroup ORADATA was dismounted SUCCESS: diskgroup ORABACKUP was dismounted Wed Dec 26 11:56:59 2007
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 Wed Dec 26 11:57:05 2007
freeing rdom 0
Wed Dec 26 11:58:31 2007
Starting ORACLE instance (normal)
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
Interface type 1 Private 192.168.70.0 configured from OCR for use as a cluster interconnect
Interface type 1 Public 10.45.5.0 configured from OCR for use as a public interface
Picked latch-free SCN scheme 3
Autotune of undo retention is turned on. LICENSE_MAX_USERS = 0
SYS auditing is disabled
ksdpec: called for event 13740 prior to event group initialization Starting up ORACLE RDBMS Version: 10.2.0.2.0. System parameters with non-default values:

  processes                = 500
  sessions                 = 555

__shared_pool_size = 1711276032
__large_pool_size = 0
__java_pool_size = 16777216
__streams_pool_size = 0
trace_enabled = FALSE nls_language = AMERICAN nls_territory = UNITED KINGDOM sga_target = 12884901888 control_files = +ORADATA/edwprd/controlfile/current. 256.620240201, +ORABACKUP/edwprd/controlfile/current.256.620240201 db_block_size = 16384
__db_cache_size = 11140071424
db_writer_processes = 8 compatible = 10.2.0.2.0 log_archive_dest_1 = LOCATION=+ORABACKUP/EDWPRD/ log_archive_format = ARC%S_%R.%T db_file_multiblock_read_count= 16 cluster_database = TRUE cluster_database_instances= 2 db_create_file_dest = +ORADATA

  db_recovery_file_dest = +ORABACKUP
  db_recovery_file_dest_size= 10737418240
  thread                   = 1
  instance_number          = 1
  undo_management          = AUTO
  undo_tablespace          = UNDOTBS1
  remote_login_passwordfile= EXCLUSIVE
  db_domain                =
  dispatchers              = (PROTOCOL=TCP) (SERVICE=EDWPRDXDB)
  remote_listener          = LISTENERS_EDWPRD
  job_queue_processes      = 10
  audit_file_dest          = D:\ORACLE\PRODUCT\10.2.0\ADMIN\EDWPRD
\ADUMP
  background_dump_dest     = D:\ORACLE\PRODUCT\10.2.0\ADMIN\EDWPRD
\BDUMP
  user_dump_dest           = D:\ORACLE\PRODUCT\10.2.0\ADMIN\EDWPRD
\UDUMP
  max_dump_file_size       = 1024
  core_dump_dest           = D:\ORACLE\PRODUCT\10.2.0\ADMIN\EDWPRD
\CDUMP
  db_name                  = EDWPRD
  open_cursors             = 300
  optimizer_mode           = choose
  pga_aggregate_target     = 1707081728

Cluster communication is configured to use the following interface(s) for this instance
  192.168.70.11
Wed Dec 26 11:58:37 2007
cluster interconnect IPC version:Oracle 9i Winsock2 TCP/IP IPC IPC Vendor 0 proto 0
  Version 0.0
PMON started with pid=2, OS id=7116
DIAG started with pid=6, OS id=6880
PSP0 started with pid=10, OS id=6476
LMON started with pid=14, OS id=6856

Wed Dec 26 11:58:39 2007
ORA-00130: invalid listener address '(ADDRESS=(PROTOCOL=TCP) (HOST=BRNORA62-vip)(PORT=1521))'
LMD0 started with pid=18, OS id=7016
LMS0 started with pid=22, OS id=6728
LMS1 started with pid=26, OS id=4036
MMAN started with pid=30, OS id=6204
DBW0 started with pid=34, OS id=448
DBW1 started with pid=38, OS id=5492
DBW2 started with pid=42, OS id=4436
DBW3 started with pid=46, OS id=5960
DBW4 started with pid=50, OS id=6324
DBW5 started with pid=54, OS id=5700
DBW6 started with pid=58, OS id=2828
DBW7 started with pid=62, OS id=4612
LGWR started with pid=66, OS id=3952
CKPT started with pid=70, OS id=1572
SMON started with pid=74, OS id=6288
RECO started with pid=78, OS id=5860
CJQ0 started with pid=82, OS id=6672
MMON started with pid=86, OS id=5288
MMNL started with pid=90, OS id=6976

Wed Dec 26 11:58:39 2007
starting up 1 dispatcher(s) for network address '(ADDRESS=(PARTIAL=YES) (PROTOCOL=TCP))'...
starting up 1 shared server(s) ...
Wed Dec 26 11:58:39 2007
lmon registered with NM - instance id 1 (internal mem no 0) Wed Dec 26 11:58:41 2007
Reconfiguration started (old inc 0, new inc 2) List of nodes:
 0
 Global Resource Directory frozen
* allocate domain 0, invalid = TRUE
 Communication channels reestablished
 Master broadcasted resource hash value bitmaps  Non-local Process blocks cleaned out
Wed Dec 26 11:58:41 2007
 LMS 1: 0 GCS shadows cancelled, 0 closed Wed Dec 26 11:58:42 2007
 LMS 0: 0 GCS shadows cancelled, 0 closed  Set master node info
 Submitted all remote-enqueue requests
 Dwn-cvts replayed, VALBLKs dubious
 All grantable enqueues granted
 Post SMON to start 1st pass IR
Wed Dec 26 11:58:42 2007
 LMS 0: 0 GCS shadows traversed, 0 replayed Wed Dec 26 11:58:42 2007
 LMS 1: 0 GCS shadows traversed, 0 replayed Wed Dec 26 11:58:42 2007
 Submitted all GCS remote-cache requests  Post SMON to start 1st pass IR
 Fix write in gcs resources
Reconfiguration complete
LCK0 started with pid=102, OS id=1876
Wed Dec 26 11:58:43 2007
ALTER DATABASE MOUNT
Wed Dec 26 11:58:43 2007
This instance was first to mount
Wed Dec 26 11:58:43 2007
Starting background process ASMB
ASMB started with pid=110, OS id=5428
Starting background process RBAL
RBAL started with pid=114, OS id=4344
Wed Dec 26 11:58:48 2007
SUCCESS: diskgroup ORADATA was mounted
SUCCESS: diskgroup ORABACKUP was mounted Wed Dec 26 11:58:52 2007
Setting recovery target incarnation to 1 Wed Dec 26 11:58:52 2007
Successful mount of redo thread 1, with mount id 606843251 Wed Dec 26 11:58:52 2007
Database mounted in Shared Mode (CLUSTER_DATABASE=TRUE) Completed: ALTER DATABASE MOUNT
Wed Dec 26 11:58:52 2007
ALTER DATABASE OPEN
This instance was first to open
Picked broadcast on commit scheme to generate SCNs Wed Dec 26 11:58:53 2007
LGWR: STARTING ARCH PROCESSES
ARC0 started with pid=134, OS id=4724
Wed Dec 26 11:58:53 2007
ARC0: Archival started
ARC1 started with pid=138, OS id=4700
Wed Dec 26 11:58:53 2007
ARC1: Archival started
LGWR: STARTING ARCH PROCESSES COMPLETE
SUCCESS: diskgroup ORAREDO was mounted
Thread 1 opened at log sequence 15521
  Current log# 6 seq# 15521 mem# 0: +ORAREDO/edwprd/onlinelog/ group_6.257.630862051
  Current log# 6 seq# 15521 mem# 1: +ORAREDO/edwprd/onlinelog/ group_6.256.630862053
Successful open of redo thread 1
Wed Dec 26 11:58:53 2007
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set Wed Dec 26 11:58:53 2007
ARC1: STARTING ARCH PROCESSES
Wed Dec 26 11:58:53 2007
ARC0: Becoming the 'no FAL' ARCH
ARC0: Becoming the 'no SRL' ARCH
Wed Dec 26 11:58:53 2007
ARC2: Archival started
ARC2 started with pid=142, OS id=4256
Wed Dec 26 11:58:53 2007
SMON: enabling cache recovery
Wed Dec 26 11:58:53 2007
ARC1: STARTING ARCH PROCESSES COMPLETE
ARC1: Becoming the heartbeat ARCH
Wed Dec 26 11:58:54 2007
Successfully onlined Undo Tablespace 1.
Wed Dec 26 11:58:54 2007
SMON: enabling tx recovery
Wed Dec 26 11:58:54 2007
Database Characterset is WE8MSWIN1252
Wed Dec 26 11:58:54 2007
Instance recovery: looking for dead threads Instance recovery: lock domain invalid but no dead threads Wed Dec 26 11:58:54 2007
replication_dependency_tracking turned off (no async multimaster replication found)
Starting background process QMNC
QMNC started with pid=146, OS id=4912
Wed Dec 26 11:58:58 2007
Completed: ALTER DATABASE OPEN
Wed Dec 26 11:58:58 2007
db_recovery_file_dest_size of 10240 MB is 0.21% 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. Wed Dec 26 11:59:53 2007
Shutting down archive processes
Wed Dec 26 11:59:58 2007
ARCH shutting down
ARC2: Archival stopped Received on Wed Dec 26 2007 - 05:38:10 CST

Original text of this message