Jobs failure broken

**cyril** · 16/03/2012, 10h20

Bonjour,

Le lance un job oracle tous les jours à la même heure.
De temps en temps, le job fait 11 tentatives avant de se déclencher
correctement. Broken est égal à N.
J'aimerai savoir pour quelle raison il fait plusieurs tentatives.
Est-ce du à la sauvegarde de la base oracle ?
Est-ce du à une mise à jours windows ?
etc..
Si quelqu'un a des idées ?
merci

Cyril

Oracle 10.2.0.10 G
windows 2003 R2 pack 2

**Heaven93** · 16/03/2012, 16h39

bonjour,

que fait ce job?
que dit l'alert.log à ce moment-là?
quelle est la valeur de job_queue_processes?

**cyril** · 16/03/2012, 17h41

merci de ta réponse.
Mon job doit se lancer à 2:00 du matin.
Il lance une procédure stockée. Celle-ci fonctionne bien.
La valeur de job_queue_processes est 10.
En regardant le alert.log, j'ai l'impression que mon job se déclenche la première fois sans succès à 03:49:30.
Le message ORA-20000: Le moteur d'édition est occupé, essayez ultérieurement ! vient de ma procédure stockée. Je l'ai créé.
La, je sais pourquoi.
Par contre, j'aimerai savoir pourquoi mon job s'est déclenché 03:49:30 au lieu de 2h00.
J'ai vérifier dans USER_JOBS, la valeur de NEXT_SEC est bien 2:00.
Merci d'avance de votre aide

Voici le alert.log

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
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
 
Thu Mar 15 00:12:44 2012
Thread 1 advanced to log sequence 18581
  Current log# 1 seq# 18581 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO01.LOG
Thu Mar 15 02:00:11 2012
Thread 1 advanced to log sequence 18582
  Current log# 2 seq# 18582 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO02.LOG
Thread 1 advanced to log sequence 18583
  Current log# 3 seq# 18583 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO03.LOG
Thu Mar 15 02:00:34 2012
Thread 1 cannot allocate new log, sequence 18584
Checkpoint not complete
  Current log# 3 seq# 18583 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO03.LOG
Thread 1 advanced to log sequence 18584
  Current log# 1 seq# 18584 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO01.LOG
Thu Mar 15 02:01:04 2012
Thread 1 advanced to log sequence 18585
  Current log# 2 seq# 18585 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO02.LOG
Thu Mar 15 02:01:21 2012
Thread 1 cannot allocate new log, sequence 18586
Checkpoint not complete
  Current log# 2 seq# 18585 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO02.LOG
Thu Mar 15 02:01:42 2012
Thread 1 advanced to log sequence 18586
  Current log# 3 seq# 18586 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO03.LOG
Thread 1 advanced to log sequence 18587
  Current log# 1 seq# 18587 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO01.LOG
Thu Mar 15 02:02:09 2012
Thread 1 advanced to log sequence 18588
  Current log# 2 seq# 18588 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO02.LOG
Thu Mar 15 02:02:35 2012
Thread 1 advanced to log sequence 18589
  Current log# 3 seq# 18589 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO03.LOG
Thu Mar 15 02:02:48 2012
Thread 1 cannot allocate new log, sequence 18590
Checkpoint not complete
  Current log# 3 seq# 18589 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO03.LOG
Thu Mar 15 02:02:58 2012
Thread 1 advanced to log sequence 18590
  Current log# 1 seq# 18590 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO01.LOG
Thu Mar 15 02:03:20 2012
Thread 1 advanced to log sequence 18591
  Current log# 2 seq# 18591 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO02.LOG
Thu Mar 15 02:03:48 2012
Thread 1 advanced to log sequence 18592
  Current log# 3 seq# 18592 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO03.LOG
Thu Mar 15 02:05:56 2012
Thread 1 advanced to log sequence 18593
  Current log# 1 seq# 18593 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO01.LOG
Thu Mar 15 02:44:14 2012
Thread 1 advanced to log sequence 18594
  Current log# 2 seq# 18594 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO02.LOG
Dump file e:\oracle\product\10.2.0/admin/ecandela/bdump\alert_ecandela.log
Thu Mar 15 03:47:32 2012
ORACLE V10.2.0.1.0 - Production vsnsta=0
vsnsql=14 vsnxtr=3
Windows NT Version V5.2 Service Pack 2
CPU                 : 2 - type 586, 1 Physical Cores
Process Affinity    : 0x00000000
Memory (Avail/Total): Ph:2638M/3325M, Ph+PgF:4381M/4711M, VA:1939M/2047M
Thu Mar 15 03:47:32 2012
Starting ORACLE instance (normal)
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
Picked latch-free SCN scheme 2
Using LOG_ARCHIVE_DEST_10 parameter default value as USE_DB_RECOVERY_FILE_DEST
Autotune of undo retention is turned on. 
IMODE=BR
ILAT =18
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.1.0.
System parameters with non-default values:
  processes                = 150
  __shared_pool_size       = 83886080
  __large_pool_size        = 4194304
  __java_pool_size         = 4194304
  __streams_pool_size      = 0
  spfile                   = E:\ORACLE\PRODUCT\10.2.0\DB_1\DBS\SPFILEECANDELA.ORA
  sga_target               = 612368384
  control_files            = E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\CONTROL01.CTL, E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\CONTROL02.CTL, E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\CONTROL03.CTL
  db_block_size            = 8192
  __db_cache_size          = 515899392
  compatible               = 10.2.0.1.0
  db_file_multiblock_read_count= 16
  db_recovery_file_dest    = E:\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=ECANDELAXDB)
  job_queue_processes      = 10
  audit_file_dest          = E:\ORACLE\PRODUCT\10.2.0\ADMIN\ECANDELA\ADUMP
  background_dump_dest     = E:\ORACLE\PRODUCT\10.2.0\ADMIN\ECANDELA\BDUMP
  user_dump_dest           = E:\ORACLE\PRODUCT\10.2.0\ADMIN\ECANDELA\UDUMP
  core_dump_dest           = E:\ORACLE\PRODUCT\10.2.0\ADMIN\ECANDELA\CDUMP
  db_name                  = ECANDELA
  open_cursors             = 300
  pga_aggregate_target     = 203423744
PMON started with pid=2, OS id=152
PSP0 started with pid=3, OS id=200
MMAN started with pid=4, OS id=196
DBW0 started with pid=5, OS id=800
LGWR started with pid=6, OS id=864
CKPT started with pid=7, OS id=604
SMON started with pid=8, OS id=968
RECO started with pid=9, OS id=1024
CJQ0 started with pid=10, OS id=1040
MMON started with pid=11, OS id=688
MMNL started with pid=12, OS id=1128
Thu Mar 15 03:47:45 2012
starting up 1 dispatcher(s) for network address '(ADDRESS=(PARTIAL=YES)(PROTOCOL=TCP))'...
starting up 1 shared server(s) ...
Oracle Data Guard is not available in this edition of Oracle.
Thu Mar 15 03:47:46 2012
alter database mount exclusive
Thu Mar 15 03:47:56 2012
Setting recovery target incarnation to 2
Thu Mar 15 03:47:57 2012
Successful mount of redo thread 1, with mount id 941774114
Thu Mar 15 03:47:57 2012
Database mounted in Exclusive Mode
Completed: alter database mount exclusive
Thu Mar 15 03:47:57 2012
alter database open
Thu Mar 15 03:47:59 2012
Beginning crash recovery of 1 threads
Thu Mar 15 03:48:00 2012
Started redo scan
Thu Mar 15 03:48:01 2012
Completed redo scan
 45556 redo blocks read, 7668 data blocks need recovery
Thu Mar 15 03:48:07 2012
Started redo application at
 Thread 1: logseq 18594, block 17639
Thu Mar 15 03:48:07 2012
Recovery of Online Redo Log: Thread 1 Group 2 Seq 18594 Reading mem 0
  Mem# 0 errs 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO02.LOG
Thu Mar 15 03:48:30 2012
Completed redo application
Thu Mar 15 03:48:30 2012
Completed crash recovery at
 Thread 1: logseq 18594, block 63195, scn 329993208
 7668 data blocks read, 7653 data blocks written, 45556 redo blocks read
Thu Mar 15 03:48:56 2012
Thread 1 advanced to log sequence 18595
Thread 1 opened at log sequence 18595
  Current log# 3 seq# 18595 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO03.LOG
Successful open of redo thread 1
Thu Mar 15 03:49:00 2012
SMON: enabling cache recovery
Thu Mar 15 03:49:05 2012
Successfully onlined Undo Tablespace 1.
Thu Mar 15 03:49:05 2012
SMON: enabling tx recovery
Thu Mar 15 03:49:05 2012
Database Characterset is WE8MSWIN1252
replication_dependency_tracking turned off (no async multimaster replication found)
Starting background process QMNC
QMNC started with pid=16, OS id=468
Thu Mar 15 03:49:20 2012
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 Mar 15 03:49:21 2012
Completed: alter database open
Thu Mar 15 03:49:30 2012
Errors in file e:\oracle\product\10.2.0\admin\ecandela\bdump\ecandela_j000_4256.trc:
ORA-12012: erreur d'exécution automatique du travail 762
ORA-20000: Le moteur d'édition est occupé, essayez ultérieurement !
ORA-06512: à "ATLOG.PKG_EDITION", ligne 295
ORA-06512: à ligne 1
 
Thu Mar 15 03:51:31 2012
Errors in file e:\oracle\product\10.2.0\admin\ecandela\bdump\ecandela_j001_4260.trc:
ORA-12012: erreur d'exécution automatique du travail 762
ORA-20000: Le moteur d'édition est occupé, essayez ultérieurement !
ORA-06512: à "ATLOG.PKG_EDITION", ligne 295
ORA-06512: à ligne 1
 
Thu Mar 15 03:55:36 2012
Errors in file e:\oracle\product\10.2.0\admin\ecandela\bdump\ecandela_j000_5956.trc:
ORA-12012: erreur d'exécution automatique du travail 762
ORA-20000: Le moteur d'édition est occupé, essayez ultérieurement !
ORA-06512: à "ATLOG.PKG_EDITION", ligne 295
ORA-06512: à ligne 1
 
Thu Mar 15 04:03:41 2012
Errors in file e:\oracle\product\10.2.0\admin\ecandela\bdump\ecandela_j000_2324.trc:
ORA-12012: erreur d'exécution automatique du travail 762
ORA-20000: Le moteur d'édition est occupé, essayez ultérieurement !
ORA-06512: à "ATLOG.PKG_EDITION", ligne 295
ORA-06512: à ligne 1
 
Thu Mar 15 04:19:46 2012
Errors in file e:\oracle\product\10.2.0\admin\ecandela\bdump\ecandela_j000_4844.trc:
ORA-12012: erreur d'exécution automatique du travail 762
ORA-20000: Le moteur d'édition est occupé, essayez ultérieurement !
ORA-06512: à "ATLOG.PKG_EDITION", ligne 295
ORA-06512: à ligne 1
 
Thu Mar 15 04:51:52 2012
Errors in file e:\oracle\product\10.2.0\admin\ecandela\bdump\ecandela_j000_6100.trc:
ORA-12012: erreur d'exécution automatique du travail 762
ORA-20000: Le moteur d'édition est occupé, essayez ultérieurement !
ORA-06512: à "ATLOG.PKG_EDITION", ligne 295
ORA-06512: à ligne 1
 
Thu Mar 15 05:00:52 2012
Thread 1 advanced to log sequence 18596
  Current log# 1 seq# 18596 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO01.LOG
Thu Mar 15 05:55:56 2012
Errors in file e:\oracle\product\10.2.0\admin\ecandela\bdump\ecandela_j000_5152.trc:
ORA-12012: erreur d'exécution automatique du travail 762
ORA-20000: Le moteur d'édition est occupé, essayez ultérieurement !
ORA-06512: à "ATLOG.PKG_EDITION", ligne 295
ORA-06512: à ligne 1
 
Thu Mar 15 06:00:00 2012
Unable to restore resource manager plan to '':
ORA-02097: parameter cannot be modified because specified value is invalid
ORA-00439: feature not enabled: Database resource manager
Thu Mar 15 08:04:02 2012
Errors in file e:\oracle\product\10.2.0\admin\ecandela\bdump\ecandela_j000_5760.trc:
ORA-12012: erreur d'exécution automatique du travail 762
ORA-20000: Le moteur d'édition est occupé, essayez ultérieurement !
ORA-06512: à "ATLOG.PKG_EDITION", ligne 295
ORA-06512: à ligne 1
 
Thu Mar 15 09:02:03 2012
Thread 1 advanced to log sequence 18597
  Current log# 2 seq# 18597 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO02.LOG
Thu Mar 15 12:07:31 2012
Thread 1 advanced to log sequence 18598
  Current log# 3 seq# 18598 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO03.LOG
Thu Mar 15 12:20:06 2012
Errors in file e:\oracle\product\10.2.0\admin\ecandela\bdump\ecandela_j000_680.trc:
ORA-12012: erreur d'exécution automatique du travail 762
ORA-20000: Le moteur d'édition est occupé, essayez ultérieurement !
ORA-06512: à "ATLOG.PKG_EDITION", ligne 295
ORA-06512: à ligne 1
 
Thu Mar 15 14:51:16 2012
Thread 1 advanced to log sequence 18599
  Current log# 1 seq# 18599 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO01.LOG
Thu Mar 15 18:00:11 2012
Thread 1 advanced to log sequence 18600
  Current log# 2 seq# 18600 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ECANDELA\REDO02.LOG
Thu Mar 15 20:52:08 2012
Errors in file e:\oracle\product\10.2.0\admin\ecandela\bdump\ecandela_j000_4364.trc:
ORA-12012: erreur d'exécution automatique du travail 762
ORA-20000: Le moteur d'édition est occupé, essayez ultérieurement !
ORA-06512: à "ATLOG.PKG_EDITION", ligne 295
ORA-06512: à ligne 1

**Heaven93** · 17/03/2012, 13h05

bonjour,

oracle a peut-être son scheduler à l'heure de greenwich ;-)
il y a quand même un mystère. pas de shutdown propre mais un startup avec crach recovery (évidemment). supposition : le job a essayé de se lancer (à 3h) mais la base était down. et pour savoir quel sera son comportement en cas de failure, c'est plutôt dans la table user_scheduler_jobs qu'il faut regarder.
en cas de doute sur l"heure du scheduler, essaie de lancer le job dans la journée pour voir s'il n'y a pas de décalage entre l'heure programmée et l'heure réelle. ensuite il serait bon de fermer la base proprement avant de l'ouvrir de nouveau.

**cyril** · 19/03/2012, 14h35

Bonjour,

Merci de ta réponse.
Je n'ai pas acces au serveur aujourd'hui.
Tu veux dire quoi exactement par :

il y a quand même un mystère. pas de shutdown propre mais un startup avec crach recovery (évidemment).

a+

**Heaven93** · 26/03/2012, 19h51

ce que je veux dire c'est que dans l'alert.log on voit un switch de log à 2h44, 3h47 un démarrage mais pas de shutdown entre les deux. d'où le crash recovery ligne 129.

Jobs failure broken

Oracle

Vue hybride

Discussions similaires

Partager

Partager