Discussion :

[cedrich]

Bonjour,

J'ai une base de données sur laquelle j'ai appliqué les archives logs. Le soir je fais une copie des tablspaces ainsi que dump. J'arrête le service (net stop ...) via une tâche planifiée et j'effectues mes sauvegardes. Mes sauvegardes terminées je relance le service afin que la base soit de nouveau dispo.

Cela fonctionne presque parfaitement. En effet, il arrive parfois que la base ne descende pas "correctement" et elle reste "bloquée".

Dans l'alert log d'Oracle j'ai les cas suivants :

Cas fonctionel :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
Mon Nov 19 21:33:26 2007
Shutting down instance: further logons disabled
Shutting down instance (immediate)
License high water mark = 67
Mon Nov 19 21:33:28 2007
alter database close normal
Mon Nov 19 21:33:28 2007
SMON: disabling tx recovery
SMON: disabling cache recovery
Mon Nov 19 21:33:28 2007
Shutting down archive processes
Archiving is disabled
Mon Nov 19 21:33:28 2007
ARCH shutting down
Mon Nov 19 21:33:28 2007
ARC0: Archival stopped
Mon Nov 19 21:33:28 2007
Thread 1 closed at log sequence 40621
Successful close of redo thread 1.
Mon Nov 19 21:33:28 2007
Completed: alter database close normal
Mon Nov 19 21:33:28 2007
alter database dismount
Mon Nov 19 21:33:29 2007
ARCH shutting down
Mon Nov 19 21:33:29 2007
ARC1: Archival stopped
Mon Nov 19 21:33:30 2007
Completed: alter database dismount
ARCH: Archiving is disabled
Shutting down archive processes
Archiving is disabled
Archive process shutdown avoided: 0 active
ARCH: Archiving is disabled
Shutting down archive processes
Archiving is disabled
Archive process shutdown avoided: 0 active
Dump file c:\oracle\admin\idprod\bdump\alert_idprod.log

Cas posant le problème :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
Mon Nov 19 21:33:26 2007
Shutting down instance: further logons disabled
Shutting down instance (immediate)
License high water mark = 67
Mon Nov 19 21:33:28 2007
alter database close normal
Mon Nov 19 21:33:28 2007
SMON: disabling tx recovery
SMON: disabling cache recovery
Mon Nov 19 21:33:28 2007
Shutting down archive processes
Archiving is disabled
Mon Nov 19 21:33:28 2007
ARCH shutting down
Mon Nov 19 21:33:28 2007
ARC0: Archival stopped
Mon Nov 19 21:33:28 2007
Thread 1 closed at log sequence 40621
Successful close of redo thread 1.
Mon Nov 19 21:33:28 2007
Completed: alter database close normal
Mon Nov 19 21:33:28 2007
alter database dismount
Mon Nov 19 21:33:29 2007
ARCH shutting down
Mon Nov 19 21:33:29 2007
ARC1: Archival stopped
Mon Nov 19 21:33:30 2007
Completed: alter database dismount
ARCH: Archiving is disabled
Shutting down archive processes
Archiving is disabled
Archive process shutdown avoided: 0 active
ARCH: Archiving is disabled
Shutting down archive processes
Archiving is disabled
Archive process shutdown avoided: 0 active
partie manquante
Dump file c:\oracle\admin\idprod\bdump\alert_idprod.log

Comme vous pouvez le voir en rouge, la base ne descends pas le processus d'archive. Et la base ne fait plus de transactions à moins d'un redémarrage manuelle de la base.

J'ai vérifié si c'était lié à un problème de place, s'il y avait des informations dans l'observateurs d'événements, sans succès.

Est-ce que quelqu'un aurait une idée de quoi pourrait provenir ce problème. Il n'est pas systématique et cela peut fonctionner pendant plusieurs jours et tout d'un coup cela "plante" 1x fois. Après le redémarrage manuelle, c'est de nouveau bon pour 1 j, 2j, ... 1 mois,...

Merci d'avance de votre précieuse aide.

Cédric

[LeoAnderson]

Dans le cas où ça marche pas, pouvez-vous poster toute l'alert ?
(de l'instruction shutdown au premier log swicth après le redémarrage))

[cedrich]

Voici un cas complet qui n'a pas fonctionné :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
Wed Sep 26 21:35:10 2007
ARC1: Evaluating archive   log 2 thread 1 sequence 5771
ARC1: Beginning to archive log 2 thread 1 sequence 5771
Creating archive destination LOG_ARCHIVE_DEST_1: 'D:\ORACLE\ORADATA\IDPROD\ARCHIVES\ARCHIVE_IDPROD_1_5771.DBF'
ARC1: Completed archiving  log 2 thread 1 sequence 5771
Wed Sep 26 22:30:00 2007
Shutting down instance: further logons disabled
Shutting down instance (immediate)
License high water mark = 6
Wed Sep 26 22:30:03 2007
ALTER DATABASE CLOSE NORMAL
Wed Sep 26 22:30:03 2007
SMON: disabling tx recovery
SMON: disabling cache recovery
Wed Sep 26 22:30:03 2007
Shutting down archive processes
Archiving is disabled
Wed Sep 26 22:30:03 2007
ARCH shutting down
ARC0: Archival stopped
Wed Sep 26 22:30:03 2007
ARCH shutting down
ARC1: Archival stopped
Wed Sep 26 22:30:03 2007
Thread 1 closed at log sequence 5772
Successful close of redo thread 1.
Wed Sep 26 22:30:03 2007
Completed: ALTER DATABASE CLOSE NORMAL
Wed Sep 26 22:30:03 2007
ALTER DATABASE DISMOUNT
Completed: ALTER DATABASE DISMOUNT
Dump file c:\oracle\admin\idprod\bdump\alert_idprod.log
Thu Sep 27 09:42:42 2007
ORACLE V9.2.0.1.0 - Production vsnsta=0
vsnsql=12 vsnxtr=3
Windows 2000 Version 5.2 , CPU type 586
Thu Sep 27 09:42:42 2007
Starting ORACLE instance (normal)
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
SCN scheme 2
Using log_archive_dest parameter default value
LICENSE_MAX_USERS = 0
SYS auditing is disabled
Starting up ORACLE RDBMS Version: 9.2.0.1.0.
System parameters with non-default values:
  processes                = 150
  timed_statistics         = TRUE
  shared_pool_size         = 50331648
  large_pool_size          = 8388608
  java_pool_size           = 0
  control_files            = C:\oracle\controlfile\IDPROD\controlfilecontrol01.ctl, D:\oracle\controlfile\IDPROD\controlfilecontrol02.ctl, D:\oracle\controlfile\IDPROD\controlfilecontrol03.ctl
  db_block_size            = 8192
  db_cache_size            = 25165824
  compatible               = 9.2.0.0.0
  log_archive_start        = TRUE
  log_archive_dest_1       = LOCATION=D:\Oracle\oradata\IDPROD\archives
  log_archive_format       = ARCHIVE_IDPROD_%t_%s.dbf
  db_file_multiblock_read_count= 16
  fast_start_mttr_target   = 300
  undo_management          = AUTO
  undo_tablespace          = UNDOTBS1
  undo_retention           = 10800
  remote_login_passwordfile= EXCLUSIVE
  db_domain                = SCHCDF.CH
  instance_name            = IDPROD
  job_queue_processes      = 10
  hash_join_enabled        = TRUE
  background_dump_dest     = C:\oracle\admin\IDPROD\bdump
  user_dump_dest           = C:\oracle\admin\IDPROD\udump
  core_dump_dest           = C:\oracle\admin\IDPROD\cdump
  sort_area_size           = 524288
  db_name                  = IDPROD
  open_cursors             = 300
  star_transformation_enabled= FALSE
  query_rewrite_enabled    = FALSE
  pga_aggregate_target     = 25165824
  aq_tm_processes          = 1
PMON started with pid=2
DBW0 started with pid=3
LGWR started with pid=4
CKPT started with pid=5
SMON started with pid=6
RECO started with pid=7
CJQ0 started with pid=8
QMN0 started with pid=9
Thu Sep 27 09:42:45 2007
ARCH: STARTING ARCH PROCESSES
ARC0 started with pid=10
ARC0: Archival started
ARC1 started with pid=11
Thu Sep 27 09:42:46 2007
ARCH: STARTING ARCH PROCESSES COMPLETE
Thu Sep 27 09:42:46 2007
ARC1: Archival started
ARC1: Thread not mounted
Thu Sep 27 09:42:46 2007
ARC0: Thread not mounted
Thu Sep 27 09:42:46 2007
alter database mount exclusive 
Thu Sep 27 09:42:50 2007
Successful mount of redo thread 1, with mount id 2607647766.
Thu Sep 27 09:42:50 2007
Database mounted in Exclusive Mode.
Completed: alter database mount exclusive
Thu Sep 27 09:42:50 2007
alter database open
Thu Sep 27 09:42:50 2007
LGWR: Primary database is in CLUSTER CONSISTENT mode
Thread 1 opened at log sequence 5772
  Current log# 3 seq# 5772 mem# 0: D:\ORACLE\CONTROLFILE\IDPROD\REDOLOG03.ORA
Successful open of redo thread 1.
Thu Sep 27 09:42:50 2007
SMON: enabling cache recovery
Thu Sep 27 09:42:50 2007
Undo Segment 1 Onlined
Undo Segment 2 Onlined
Undo Segment 3 Onlined
Undo Segment 4 Onlined
Undo Segment 5 Onlined
Undo Segment 6 Onlined
Undo Segment 7 Onlined
Undo Segment 8 Onlined
Undo Segment 9 Onlined
Undo Segment 10 Onlined
Successfully onlined Undo Tablespace 1.
Thu Sep 27 09:42:50 2007
SMON: enabling tx recovery
Thu Sep 27 09:42:50 2007
Database Characterset is WE8ISO8859P15
replication_dependency_tracking turned off (no async multimaster replication found)
Completed: alter database open
Thu Sep 27 09:48:01 2007
Thread 1 advanced to log sequence 5773
  Current log# 1 seq# 5773 mem# 0: D:\ORACLE\CONTROLFILE\IDPROD\REDOLOG01.ORA
Thu Sep 27 09:48:01 2007
ARC0: Evaluating archive   log 3 thread 1 sequence 5772
ARC0: Beginning to archive log 3 thread 1 sequence 5772
Creating archive destination LOG_ARCHIVE_DEST_1: 'D:\ORACLE\ORADATA\IDPROD\ARCHIVES\ARCHIVE_IDPROD_1_5772.DBF'
ARC0: Completed archiving  log 3 thread 1 sequence 5772

En vert, le dernier archivage avant l'arrêt de la base
En orange, La partie ou il manque l'arrêt du processus d'archive
En rouge, le redémarrage manuel de l'instance jusqu'au log

Dans l'observateur d'événement, on voit une demande d'arrêt du service et il n'y a pas la confirmation de l'état du service en arrêt. Dans le cas fonctionnel, il a toujours une message pour la demande d'arrêt du service et un autre message pour indiquer que le service est dans l'état arrêté.

A dispo si vous avez besoin de plus de complément.

Salutations,

Cédric

[pifor]

ORACLE V9.2.0.1.0

Si vous être obligé de rester en version 9, essayez au moins d'utiliser le dernier patchset 9.2.0.8.

C'est probablement un bug Oracle.

Sur Metalink, la note:

Subject: Shutdown Immediate Hangs on Windows. Shutdown Transactional Works Fine.
Doc ID: Note:207952.1 Type: PROBLEM
Last Revision Date: 06-MAY-2004 Status: PUBLISHED

dit que SHUTDOWN IMMEDIATE force le ROLLBACK des transactions en cours et qu'il pourrait y avoir un problème avec la fonctionnalité "Parallel Rollback" et qu'il faudrait mettre le paramètre fast_start_parallel_rollback à FALSE.

Si vous avez un contrat de support Oracle, il faut les contacter et demander confirmation.