[WAIT EVENTS] rdbms ipc reply,smon timer

Version imprimable

Salut tout le monde,
Voici un problème bizarre,
Sur une de mes bases (9.2.0.7 sur du red hat), dropper une table peux prendre un temps fou (plusieurs minutes, voire plus).
Quand je regarde dans la vue v$session_wait , je vois une attente sur smon (colonne p1).

Code:

1
2
3
4
5
6
7
 
SQL> select * from v$session_wait where sid=41;
 
       SID       SEQ# EVENT      P1TEXT               P1 P1RAW            P2TEXT             P2 P2RAW            P3TEXT         P3 P3RAW   WAIT_TIME SECONDS_IN_WAIT STATE
---------- ---------- ---------- ------------ ---------- ---------------- ---------- ---------- ---------------- ------ ---------- ------ ---------- --------------- -------------------
        41        464 rdbms ipc  from_process          6 0000000000000006 timeout      21474780 000000000147ADDC                 0 00              0               1 WAITING
                      reply

maintenant, quand je regarde ce que fait smon

Code:

1
2
3
4
5
 
select * from v$sqltext v where v.ADDRESS=(select sql_address from v$session where sid=6)
order by piece;
 
UPDATE SMON_SCN_TIME SET SCN_WRP=:1, SCN_BAS=:2, TIME_MP=:3, TIME_DP=:4 WHERE TIME_MP = :5  AND   THREAD = :6  AND   ROWNUM <= 1

Il passe son temps à updater cetter table!!

J'ai bien essayé (en étant quasi sûre) que cela ne marcherait pas puisque smon est actif (mais bon, on peut rêver!)

Code:

1
2
3
 
SQL> ORADEBUG WAKEUP 7;
Statement processed.

Sans effet.

aussi:
une stat peut être interessante:

Code:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
 
SQL> select * from V$SYSTEM_EVENT order by 4 desc;
 
EVENT                                                            TOTAL_WAITS TOTAL_TIMEOUTS TIME_WAITED AVERAGE_WAIT TIME_WAITED_MICRO
---------------------------------------------------------------- ----------- -------------- ----------- ------------ -----------------
rdbms ipc message                                                     895821         186845   126762506          142     1267625063386
pmon timer                                                            125911          88210    26603975          211      266039747678
smon timer                                                              7292            700    25343707         3476      253437065931
SQL*Net message from client                                         24019109              0    19693581            1      196935806210
log file parallel write                                               844763              0     9245313           11       92453133546
log file switch (checkpoint incomplete)                                82215          80724     7959396           97       79593956221
free buffer waits                                                      51004          49153     4895186           96       48951856599
log buffer space                                                      265557           1206     4449985           17       44499846088
db file scattered read                                               1116468              0     2674360            2       26743602932
rdbms ipc reply                                                        68500          12981     2611031           38       26110307545
enqueue                                                               933707           3704     1779871            2       17798711956

Vous avez une idée?

23/10/2006, 21h40
orafrance

c'est pas un drop cascade ou avec des FK par hasard ?
23/10/2006, 22h37
aline

helas non
24/10/2006, 08h02
orafrance

t'as pas d'objets invalide ? T'as essayé de calculer les stats sur SYS ? T'as fait une trace ?
24/10/2006, 08h04
orafrance

Lis la note 287429.1, ça m'a l'air intéressant ;)

Citation:

Envoyé par Fred_D

t'as pas d'objets invalide ? T'as essayé de calculer les stats sur SYS ? T'as fait une trace ?

Salut Fred,
En fait, c'est un peux plus général. La machine (qui est encore en test) supporte mal la montée en charge.
Ce problème intervient donc pendant cette montée. Sinon ras.
voici un exemple avec une trace:

Code:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
 
SQL> set time on
09:40:51 SQL> 
09:43:03 SQL> 
09:43:03 SQL> 
09:43:03 SQL> 
09:43:04 SQL> CREATE TABLE test AS SELECT * FROM DUAL;
 
Table created
 
09:43:06 SQL> DROP TABLE test;
 
Table dropped
 
09:44:42 SQ

1mn 40 pour droptter un table!

Et voici la trace:

Code:

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
 
********************************************************************************
 
DROP TABLE test
 
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse       23      0.00       0.05          0          0          0           0
Execute     23      0.28    3005.19          0         23        210           0
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       46      0.28    3005.25          0         23        210           0
 
Misses in library cache during parse: 23
Optimizer goal: CHOOSE
Parsing user id: 57
 
Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  rdbms ipc reply                              1550        1.95       3003.82
  log file sync                                  23        0.40          2.15
  SQL*Net message to client                      23        0.00          0.00
  SQL*Net message from client                    23        0.27          0.51
  log buffer space                                1        0.00          0.00
********************************************************************************

Citation:

Envoyé par Fred_D

Lis la note 287429.1, ça m'a l'air intéressant

Très, mais malheureusement, j'y ai rien trouvé qui résoudrait mon problème !:roll:

27/10/2006, 14h50
jlucch

Comme le dit Fred_D , ça ressemble vraiment à un problème de statistiques sys ...

Pourquoi ne pas essayer de les mettre à jour ?
27/10/2006, 14h54
aline

Citation:

Envoyé par jlucch

Comme le dit Fred_D , ça ressemble vraiment à un problème de statistiques sys ...

Pourquoi ne pas essayer de les mettre à jour ?

C'est peut être du à un mythe, mais je n'ai jamais calculé de stats sur les objets systemes
27/10/2006, 16h16
orafrance

8O j'ai exactement le même phénoméne sur un agrandissement de UNDO suite à un "Failure to extend rollback segment" :(
27/10/2006, 16h19
aline

Citation:

Envoyé par Fred_D

8O j'ai exactement le même phénoméne sur un agrandissement de UNDO suite à un "Failure to extend rollback segment" :(

C'est à dire?
rdbms ipc reply ?
27/10/2006, 16h45
LeoAnderson

si vous trusser/stracer les processes serveurs associés, est-ce que vous constatez des problèmes au niveau des shared memory ou des sémaphores ?

un ipcs -a vous confirme-t-il que les date de dernier accès (CTIME) évolue dans le temps ?

[edit] Sur un système où tourne plusieurs instances, pour connaitre les identifiants des composants IPC, il faut faire un sysresv au prompt OS (depuis la 10g)
[/edit]

Citation:

Envoyé par LeoAnderson

si vous trusser/stracer les processes serveurs associés, est-ce que vous constatez des problèmes au niveau des shared memory ou des sémaphores ?

Comment voir ceci?

Citation:

Envoyé par LeoAnderson

un ipcs -a vous confirme-t-il que les date de dernier accès (CTIME) évolue dans le temps ?

Même question!
Code:

1 2 3 4 5 6 7 8 9 10 11 12 13 ipcs -a ------ Shared Memory Segments -------- key shmid owner perms bytes nattch status 0x280827a4 32768 oracle 600 2652897280 18 ------ Semaphore Arrays -------- key semid owner perms nsems 0xa0f6c27c 229376 oracle 640 254 ------ Message Queues -------- key msqid owner perms used-bytes messages

27/10/2006, 17h19
flonardi

le rdbms ipc reply est due à un background process qui attend en l'occurence ton smon. Il y a peut être un lock de positionner ou tu swaps de trop.

Une indication peut être:
http://www.ixora.com.au/q+a/waits.htm
27/10/2006, 18h31
LeoAnderson

1. Si tu vois que ce sont toujours les mêmes routines qui sont appellées et/ou s'il y a des erreurs dans la séquence d'instructions envoyées par ton process.
(il faut le faire pour chacun des process "BACKGROUND" + pour celui de ta session)

2. Ah ben flûte... t'as pas une sortie aussi complète que celle de Solaris...

3. le lien de flonardi est intérêssant mais quand je le lis, je comprend qu'il faut regarder du côté des checkpoints mais je pense que ça, tu l'as tuné...

est-ce que tu peux tracer (event 10046, level 8 ou 12) le drop de ta table et nous communiquer la trace complète sans passsage au tkprof ?

[edit]Au fait, ton tbs est en gestion locale ?[/edit]
01/11/2006, 15h51
orafrance

Citation:

Envoyé par aline

C'est à dire?
rdbms ipc reply ?

oui, et en fait l'attente était causée par un process qui utilisé tout le UNDO :roll:; les autre transactions étaient donc bloquées :(