Discussion :

[nutopia]

Hello,

j'ai eu un crash de mon instance Informix Dynamic Server en 11.5TC6WE

voici le 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
14:48:18  Maximum server connections 32 
14:48:18  Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 49, Llog used 20
 
14:53:18  Checkpoint Completed:  duration was 0 seconds.
14:53:18  Tue Oct 18 - loguniq 53962, logpos 0x3a018, timestamp: 0xf6308a23 Interval: 47866
 
14:53:18  Maximum server connections 32 
14:53:18  Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 5, Llog used 8
 
14:56:32  Assert Failed: Unhandled NT Exception!
14:56:32   See Also: C:\IBM\IDS11_50TC3\tmp\af.cc3777f
14:56:32  Assert Failed: No Exception Handler
14:56:32  IBM Informix Dynamic Server Version 11.50.TC6WE  
14:56:32   Who: Session(2199, informix@machine.domaine, -1, 00000000)
		Thread(2267, sqlexec, 0, 4)
		File: mtex.c Line: 1146
14:56:32   Results: Exception Caught. Type: MT_EX_OS, Context: mem
14:56:32   Action: Please notify IBM Informix Technical Support.
14:56:32  stack trace for pid 7744 written to C:\IBM\IDS11_50TC3\tmp\af.cc3777f
14:56:32   See Also: C:\IBM\IDS11_50TC3\tmp\af.cc3777f, shmem.cc3777f.0
14:56:36  Releasing server from system block
14:57:45  PANIC: Attempting to bring system down
14:57:45  mtex.c, line 1146, thread 2267, proc id 7744, No Exception Handler.
15:01:39  IBM Informix Dynamic Server Started.
15:01:39  Dynamically allocated new virtual shared memory segment (size 73728KB)
15:01:39  Memory sizes:resident:931456 KB, virtual:1005184 KB, no SHMTOTAL limit
15:01:39  Requested shared memory segment size rounded from 32656KB to 32704KB
15:01:39  Dynamically allocated new virtual shared memory segment (size 32704KB)
15:01:39  Memory sizes:resident:931456 KB, virtual:1037888 KB, no SHMTOTAL limit
15:01:39  Could not disable priority aging: errno = 0
 
Tue Oct 18 15:01:40 2011
 
15:01:40  Warning: ONCONFIG dump directory (DUMPDIR) 'C:\IBM\IDS11_50TC3\tmp' has insecure permissions
15:01:40  Booting Language <c> from module <>
15:01:40  Loading Module <CNULL>
15:01:40  Booting Language <builtin> from module <>
15:01:40  Loading Module <BUILTINNULL>
15:01:40  Could not disable priority aging: errno = 0
15:01:40  Affinitied VP 1 to phys proc 1
15:01:41  Could not disable priority aging: errno = 0
15:01:41  Affinitied VP 3 to phys proc 2
15:01:41  Could not disable priority aging: errno = 0
15:01:41  Affinitied VP 4 to phys proc 3
15:01:41  Could not disable priority aging: errno = 0
15:01:41  Affinitied VP 5 to phys proc 4
15:01:46  DR: DRAUTO is 3 (CMSM)
15:01:46  DR: ENCRYPT_HDR is 0 (HDR encryption Disabled)
15:01:46  IBM Informix Dynamic Server Version 11.50.TC6WE   Software Serial Number AAA#B000000
15:01:47  IBM Informix Dynamic Server Initialized -- Shared Memory Initialized.
 
15:01:47  Started 1 B-tree scanners.
15:01:47  B-tree scanner threshold set at 5000.
15:01:47  B-tree scanner range scan size set to -1.
15:01:48  B-tree scanner ALICE mode set to 6.
15:01:48  B-tree scanner index compression level set to med.
15:01:48  DR: Reservation of the last logical log for log backup turned on
15:01:48  DR: Trying to connect to secondary server = ol_hdr32b
15:01:49  DR: Primary server connected
15:01:49  DR: Configuration parameter values of the paired servers do not match:
              Parameter: TAPEBLK
              Current server's value: 16
              Paired  server's value: 1024
              WARNING: The parameter values must match if ontape is used as
                       backup/recovery tool.
15:01:49  DR: Secondary server needs failure recovery
 
15:01:50  Physical Recovery Started at Page (7:84735).
15:01:51  Physical Recovery Complete: 0 Pages Examined, 0 Pages Restored.
15:01:51  Logical Recovery Started.
15:01:51  10 recovery worker threads will be started.
15:01:52  Logical Recovery has reached the transaction cleanup phase.
15:01:52  Logical Recovery Complete.
	  0 Committed, 0 Rolled Back, 0 Open, 0 Bad Locks
 
15:01:53  Onconfig parameter STORAGE_FULL_ALARM modified from 0 to 3.
15:01:53  Dataskip is now OFF for all dbspaces
15:01:53  Init operation complete - Mode Online
15:01:54  Checkpoint Completed:  duration was 1 seconds.
15:01:54  Tue Oct 18 - loguniq 53962, logpos 0x3c018, timestamp: 0xf6308a53 Interval: 47867
 
15:01:54  Maximum server connections 0 
15:01:54  Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 2, Llog used 1
 
15:01:54  On-Line Mode
15:01:55  DR: Sending log 53962 (current), size 2500 pages, 2.48 percent used
15:01:57  DR: Sending Logical Logs Completed
15:01:58  DR: Primary server operational
15:01:59  Checkpoint Completed:  duration was 1 seconds.
15:01:59  Tue Oct 18 - loguniq 53962, logpos 0x3f018, timestamp: 0xf6308a6d Interval: 47868
 
15:01:59  Maximum server connections 0 
15:01:59  Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 0, Llog used 3
 
15:02:00  SCHAPI: Started dbScheduler thread.
15:02:00  Booting Language <spl> from module <>
15:02:00  Loading Module <SPLNULL>
15:02:00  SCHAPI: Started 2 dbWorker threads.
15:03:23  DR: Receive error
15:03:23  ASF Echo-Thread Server: asfcode = -25582: oserr = 0: errstr = : Network connection is broken.
 
15:03:23  DR_ERR set to -1
15:03:24  DR: Turned off on primary server
15:03:24  DR: Cannot connect to secondary server
15:03:35  DR: Primary server connected
15:03:35  DR: Configuration parameter values of the paired servers do not match:
              Parameter: TAPEBLK
              Current server's value: 16
              Paired  server's value: 1024
              WARNING: The parameter values must match if ontape is used as
                       backup/recovery tool.
15:03:35  DR: Secondary server needs failure recovery
 
15:03:36  DR: Sending log 53962 (current), size 2500 pages, 4.60 percent used
15:03:38  DR: Sending Logical Logs Completed
15:03:39  DR: Primary server operational
15:03:40  Checkpoint Completed:  duration was 1 seconds.
15:03:40  Tue Oct 18 - loguniq 53962, logpos 0x74018, timestamp: 0xf630957b Interval: 47869
 
15:03:40  Maximum server connections 1 
15:03:40  Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 61, Llog used 53

j'ai pu relancer l'instance après avoir vidé le dossier tmp

savez-vous ce qu'il s'est passé?

merci pour votre aide!

[nutopia]

ça recommence...

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
15:13:31  Assert Failed: Unhandled NT Exception!
15:13:31   See Also: C:\IBM\IDS11_50TC3\tmp\af.4287b7a
15:13:31  Assert Failed: No Exception Handler
15:13:31  IBM Informix Dynamic Server Version 11.50.TC6WE  
15:13:31   Who: Session(34, informix@machine.domaine, -1, 00000000)
		Thread(64, sqlexec, 0, 5)
		File: mtex.c Line: 1146
15:13:31   Results: Exception Caught. Type: MT_EX_OS, Context: mem
15:13:31   Action: Please notify IBM Informix Technical Support.
15:13:31  stack trace for pid 1716 written to C:\IBM\IDS11_50TC3\tmp\af.4287b7a
15:13:32   See Also: C:\IBM\IDS11_50TC3\tmp\af.4287b7a, shmem.4287b7a.0
15:13:55  Checkpoint Completed:  duration was 0 seconds.
15:13:55  Tue Oct 18 - loguniq 53962, logpos 0x86018, timestamp: 0xf630a188 Interval: 47870
 
15:13:55  Maximum server connections 4 
15:13:55  Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 40, Llog used 18
 
15:14:33  PANIC: Attempting to bring system down
15:14:33  mtex.c, line 1146, thread 64, proc id 1716, No Exception Handler.

à savoir que machine.domaine correspond à mon poste!
et je ne lui ai rien fait de terrible la pauvre :p (je mettais à jour des procédures)

[begooden-it]

Je dirais au départ un problème de communication entre primary et secondary

Code :

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

15:03:23  ASF Echo-Thread Server: asfcode = -25582: oserr = 0: errstr = : Network connection IS broken

mais surtout tu as un assert failed, ce qui est encore plus préoccupant

Code :

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

1
2
3
4
5
6
7
Assert Failed: Unhandled NT Exception!
14:56:32   See Also: C:\IBM\IDS11_50TC3\tmp\af.cc3777f
14:56:32  Assert Failed: No Exception Handler
14:56:32  IBM Informix Dynamic Server Version 11.50.TC6WE  
14:56:32   Who: Session(2199, informix@machine.domaine, -1, 00000000)
		Thread(2267, sqlexec, 0, 4)
		File: mtex.c Line: 1146

Il y a des bugs qui "trainaient" sur cette partie du code.

Regarde le contenu du fichier C:\IBM\IDS11_50TC3\tmp\af.cc3777f qui t'aidera à identifier la cause de l'assert failed

Eric

[nutopia]

Merci pour ta réponse Eric,

voici le début du contenu du fichier dans tmp:

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
Exception happened at address=0x00d43d22
Exception is EXCEPTION_ACCESS_VIOLATION (code 0xc0000005)
Attempt to write location 0xc
Register Contents:
    EAX=0x00000000  ESI=0x4a460ef8  EFLAGS=0x00010216
    EBX=0x4a361028  EDI=0x4a460000     EIP=0x00d43d22
    ECX=0x00000108  ESP=0x4a437510
    EDX=0x4a460ef8  EBP=0x4a4376d0
Call Stack for thread #64 - sqlexec
0x00D43D22 (oninit)_mt_shm_free_pool (0x4A361028, 0x0000000C, 0x00000038, 0x00000000) ebp=0x4A4376D0
0x00D4A092 (oninit)_destroy_session (0x00000000, 0x00000002, 0x0044E36B, 0x01C947F8) ebp=0x4A4376F0
0x004475CD (oninit)_sq_exit (0x4A38AE98, 0x00000000, 0x00000000, 0x01C947F8) ebp=0x4A437734
0x00DA051F (oninit)_listen_verify (0x001E2748, 0x00000000, 0x00000028, 0x0000000C) ebp=0x4A437A40
0x00DA1632 (oninit)_spawn_thread (0x00000000, 0x606C9D44, 0x00000000, 0x00000000) ebp=0x4A437FB8
0x00D647C2 (oninit)_startup (0x238D0026, 0x00000000, 0x4A438068, 0x4A41CFD8) ebp=0x4A437FF8
Frame Pointer is NULL!
Unable to continue stack trace back
15:13:31  
15:13:31  IBM Informix Dynamic Server Version 11.50.TC6WE   Software Serial Number AAA#B000000
 
15:13:31  Assert Failed: No Exception Handler
15:13:31   Who: Session(34, informix@machine.domaine, -1, 00000000)
		Thread(64, sqlexec, 0, 5)
		File: mtex.c Line: 1146
15:13:31   Results: Exception Caught. Type: MT_EX_OS, Context: mem
15:13:31   Action: Please notify IBM Informix Technical Support.
15:13:31  Raw hex dump of stack located in C:\IBM\IDS11_50TC3\tmp\af.4287b7a.rawstk
15:13:31  Stack for thread: 64 sqlexec
 
 base: 0x4a427000
  len:   69632
   pc: 0x00d41181
  tos: 0x4a4366b4
state: running
   vp: 5
 
0x00d41c27 (oninit)_afhandler(0x3, 0xf85114, 0x4a436ff8, 0x498d3878)
0x00d421ed (oninit)_afcrash_interface(0xf85114, 0x4a436ff8, 0x498d3878, 0xf84ee8)
0x00d5d57e (oninit)_NT_mt_excep_filter(0x4a437140, 0x1, 0xe2af3c, 0xfa6268)
0x00d647d5 (oninit)_startup
 
 
15:13:32   See Also: C:\IBM\IDS11_50TC3\tmp\af.4287b7a, shmem.4287b7a.0

le reste n'a pas l'air très parlant et est très long (plus de 30000 lignes)
On avait déjà remarqué que Server Studio "fait planter" l'instance quand on le ferme sans se déconnecter proprement... Là, je passais mes ordres SQL avec Server Studio également. machine.domaine correspond à mon poste
Merci beaucoup.

[begooden-it]

re:

il y a un bug en xC6 qui ressemble vaguement... Fixé en xC8.
Il faudrait voir le détail de l'assert failed

[nutopia]

OK merci on installera donc la MAJ en TC8.

[nelem75]

Bonjour,

Il y a effectivement un bogue corrigé en xC8 qui pourrait correspondre sachant qu'il est lié à l'utilisation des tables systèmes. Server Studio est le genre d'outil à faire une grande utilisation des ces tables. Il est préférable de trouver la requête aussi (dans le fichier af), qui peut indiquer un peu plus sur la nature du problème et aider à trouver le bon bogue.

La corruption mémoire a été détectée au moment de la déconnexion de la partie cliente (V. Studio). Cette corruption à toutes les chances d'avoir été créée (un peu / bien) avant sa détection. Lorsque la déconnexion intervient le moteur fait du nettoyage et là, c'est le drame... ;-)

C'est pour cela qu'il faut souvent une analyse plus approfondie dans ce genre de cas (avec pile d'exécution du thread trop générique) pour se rapprocher du bon bogue. C'est à dire une analyse des segments de mémoire partagée. Il faut voir avec le support.

En ce qui concerne le cas présent, tant qu'à mettre le moteur à jour autant que cela soit fait avec la dernière version disponible: xC9 à ce jour mais la xC9W1 devrait l'être dans les quelques jours qui viennent, maximum 2 semaines.


Hope this help.

[nutopia]

Merci pour ta réponse!