[JDEV] Memory stomp on my server
Tim Ferguson
tim.ferguson at cw.com
Wed May 1 21:13:27 CDT 2002
Hi All,
I am running 1.4.2 on Tru64 and I have a problem that indicates a memory
stomp because the CPU usage for the jabber process goes to 99%, which I
have only seen in processes when it is a memory stomp, ok, anyway I have
added extra logging to mio.c and mio_ssl.c and mio_raw.c to try to
isolate the problem. It appears that when calling a write it then dies
when it either calls SSL_write or MIO_WRITE_FUNC, depending on whether
it is an ssl connection or not. I have included the last 100 lines of
the debug output below when it hung in this case on an ssl connection.
I have tried checking every parameter but it has not helped yet.
Please, please, if anyone has any ideas let me know.
Thu May 2 00:33:19 2002 mio.c:295 completed the write
Thu May 2 00:33:19 2002 mio.c:311 going to check the value of len now:
227
Thu May 2 00:33:19 2002 mio.c:345 all done writing
Thu May 2 00:33:19 2002 mio.c:350 going to free the pool
Thu May 2 00:33:19 2002 mio.c:355 cur was equal to null
Thu May 2 00:33:19 2002 mio.c:279 write_dump writing data: <presence
from='escobal at jabber.cw.com/JabberIM'
to='christi.keiser at cwiccm.cw.com'><status>Online</status><priority>1</pr
iority><x xmlns='jabber:x:delay' from='escobal at jabber.cw.com/JabberIM'
stamp='20020502T00:33:18'/></presence>
Thu May 2 00:33:19 2002 mio.c:282 cur is not null
Thu May 2 00:33:19 2002 mio.c:284 the write pointer is not null
Thu May 2 00:33:19 2002 mio.c:287 all is ok for another write:
<presence from='escobal at jabber.cw.com/JabberIM'
to='christi.keiser at cwiccm.cw.com'><status>Online</status><priority>1</pr
iority><x xmlns='jabber:x:delay' from='escobal at jabber.cw.com/JabberIM'
stamp='20020502T00:33:18'/></presence>
Thu May 2 00:33:19 2002 mio.c:288 state is 0
Thu May 2 00:33:19 2002 mio_raw.c:58 Now going to call MIO_WRITE_FUNC
Thu May 2 00:33:19 2002 mio.c:295 completed the write
Thu May 2 00:33:19 2002 mio.c:311 going to check the value of len now:
229
Thu May 2 00:33:19 2002 mio.c:345 all done writing
Thu May 2 00:33:19 2002 mio.c:350 going to free the pool
Thu May 2 00:33:19 2002 mio.c:355 cur was equal to null
Thu May 2 00:33:19 2002 mio.c:279 write_dump writing data: <presence
from='escobal at jabber.cw.com/WORK'
to='ted.ryder at cwiccm.cw.com'><status>Online</status><priority>1</priorit
y><x xmlns='jabber:x:delay' from='escobal at jabber.cw.com/WORK'
stamp='20020502T00:27:37'/><x xmlns='jabber:x:delay'
from='escobal at jabber.cw.com/WORK' stamp='20020502T00:27:38'/></presence>
Thu May 2 00:33:19 2002 mio.c:282 cur is not null
Thu May 2 00:33:19 2002 mio.c:284 the write pointer is not null
Thu May 2 00:33:19 2002 mio.c:287 all is ok for another write:
<presence from='escobal at jabber.cw.com/WORK'
to='ted.ryder at cwiccm.cw.com'><status>Online</status><priority>1</priorit
y><x xmlns='jabber:x:delay' from='escobal at jabber.cw.com/WORK'
stamp='20020502T00:27:37'/><x xmlns='jabber:x:delay'
from='escobal at jabber.cw.com/WORK' stamp='20020502T00:27:38'/></presence>
Thu May 2 00:33:19 2002 mio.c:288 state is 0
Thu May 2 00:33:19 2002 mio_raw.c:58 Now going to call MIO_WRITE_FUNC
Thu May 2 00:33:19 2002 mio.c:295 completed the write
Thu May 2 00:33:19 2002 mio.c:311 going to check the value of len now:
303
Thu May 2 00:33:19 2002 mio.c:345 all done writing
Thu May 2 00:33:19 2002 mio.c:350 going to free the pool
Thu May 2 00:33:19 2002 mio.c:355 cur was equal to null
Thu May 2 00:33:19 2002 mio.c:279 write_dump writing data: <presence
from='escobal at jabber.cw.com/WORK'
to='mark.santarelli at cwiccm.cw.com'><status>Online</status><priority>1</p
riority><x xmlns='jabber:x:delay' from='escobal at jabber.cw.com/WORK'
stamp='20020502T00:27:37'/><x xmlns='jabber:x:delay'
from='escobal at jabber.cw.com/WORK' stamp='20020502T00:27:38'/></presence>
Thu May 2 00:33:19 2002 mio.c:282 cur is not null
Thu May 2 00:33:19 2002 mio.c:284 the write pointer is not null
Thu May 2 00:33:19 2002 mio.c:287 all is ok for another write:
<presence from='escobal at jabber.cw.com/WORK'
to='mark.santarelli at cwiccm.cw.com'><status>Online</status><priority>1</p
riority><x xmlns='jabber:x:delay' from='escobal at jabber.cw.com/WORK'
stamp='20020502T00:27:37'/><x xmlns='jabber:x:delay'
from='escobal at jabber.cw.com/WORK' stamp='20020502T00:27:38'/></presence>
Thu May 2 00:33:19 2002 mio.c:288 state is 0
Thu May 2 00:33:19 2002 mio_raw.c:58 Now going to call MIO_WRITE_FUNC
Thu May 2 00:33:19 2002 mio.c:295 completed the write
Thu May 2 00:33:19 2002 mio.c:311 going to check the value of len now:
309
Thu May 2 00:33:19 2002 mio.c:345 all done writing
Thu May 2 00:33:19 2002 mio.c:350 going to free the pool
Thu May 2 00:33:19 2002 mio.c:355 cur was equal to null
Thu May 2 00:33:19 2002 mio.c:279 write_dump writing data: <presence
from='escobal at jabber.cw.com/WORK'
to='tim.ferguson at cwiccm.cw.com'><status>Online</status><priority>1</prio
rity><x xmlns='jabber:x:delay' from='escobal at jabber.cw.com/WORK'
stamp='20020502T00:27:37'/><x xmlns='jabber:x:delay'
from='escobal at jabber.cw.com/WORK' stamp='20020502T00:27:38'/></presence>
Thu May 2 00:33:19 2002 mio.c:282 cur is not null
Thu May 2 00:33:19 2002 mio.c:284 the write pointer is not null
Thu May 2 00:33:19 2002 mio.c:287 all is ok for another write:
<presence from='escobal at jabber.cw.com/WORK'
to='tim.ferguson at cwiccm.cw.com'><status>Online</status><priority>1</prio
rity><x xmlns='jabber:x:delay' from='escobal at jabber.cw.com/WORK'
stamp='20020502T00:27:37'/><x xmlns='jabber:x:delay'
from='escobal at jabber.cw.com/WORK' stamp='20020502T00:27:38'/></presence>
Thu May 2 00:33:19 2002 mio.c:288 state is 0
Thu May 2 00:33:19 2002 mio_raw.c:58 Now going to call MIO_WRITE_FUNC
Thu May 2 00:33:19 2002 mio.c:295 completed the write
Thu May 2 00:33:19 2002 mio.c:311 going to check the value of len now:
306
Thu May 2 00:33:19 2002 mio.c:345 all done writing
Thu May 2 00:33:19 2002 mio.c:350 going to free the pool
Thu May 2 00:33:19 2002 mio.c:355 cur was equal to null
Thu May 2 00:33:19 2002 mio.c:279 write_dump writing data: <presence
from='escobal at jabber.cw.com/WORK'
to='christi.keiser at cwiccm.cw.com'><status>Online</status><priority>1</pr
iority><x xmlns='jabber:x:delay' from='escobal at jabber.cw.com/WORK'
stamp='20020502T00:27:37'/><x xmlns='jabber:x:delay'
from='escobal at jabber.cw.com/WORK' stamp='20020502T00:27:38'/></presence>
Thu May 2 00:33:19 2002 mio.c:282 cur is not null
Thu May 2 00:33:19 2002 mio.c:284 the write pointer is not null
Thu May 2 00:33:19 2002 mio.c:287 all is ok for another write:
<presence from='escobal at jabber.cw.com/WORK'
to='christi.keiser at cwiccm.cw.com'><status>Online</status><priority>1</pr
iority><x xmlns='jabber:x:delay' from='escobal at jabber.cw.com/WORK'
stamp='20020502T00:27:37'/><x xmlns='jabber:x:delay'
from='escobal at jabber.cw.com/WORK' stamp='20020502T00:27:38'/></presence>
Thu May 2 00:33:19 2002 mio.c:288 state is 0
Thu May 2 00:33:19 2002 mio_raw.c:58 Now going to call MIO_WRITE_FUNC
Thu May 2 00:33:19 2002 mio.c:295 completed the write
Thu May 2 00:33:19 2002 mio.c:311 going to check the value of len now:
308
Thu May 2 00:33:19 2002 mio.c:345 all done writing
Thu May 2 00:33:19 2002 mio.c:350 going to free the pool
Thu May 2 00:33:19 2002 mio.c:355 cur was equal to null
Thu May 2 00:33:19 2002 mio.c:357 the queue was null
Thu May 2 00:33:19 2002 mio.c:279 write_dump writing data: <presence
from='escobal at jabber.cw.com/JabberIM'
to='escobal at jabber.cw.com'><status>Online</status><priority>1</priority>
</presence>
Thu May 2 00:33:19 2002 mio.c:282 cur is not null
Thu May 2 00:33:19 2002 mio.c:284 the write pointer is not null
Thu May 2 00:33:19 2002 mio.c:287 all is ok for another write:
<presence from='escobal at jabber.cw.com/JabberIM'
to='escobal at jabber.cw.com'><status>Online</status><priority>1</priority>
</presence>
Thu May 2 00:33:19 2002 mio.c:288 state is 0
Thu May 2 00:33:19 2002 mio_ssl.c:187 Entering into _mio_ssl_write
Thu May 2 00:33:19 2002 mio_ssl.c:188 buf: <presence
from='escobal at jabber.cw.com/JabberIM'
to='escobal at jabber.cw.com'><status>Online</status><priority>1</priority>
</presence>; count: 131
Thu May 2 00:33:19 2002 mio_ssl.c:215 The ssl state is OK
Thu May 2 00:33:19 2002 mio_ssl.c:217 ssl is not null
Thu May 2 00:33:19 2002 mio.c:295 completed the write
Thu May 2 00:33:19 2002 mio.c:311 going to check the value of len now:
131
Thu May 2 00:33:19 2002 mio.c:345 all done writing
Thu May 2 00:33:19 2002 mio.c:350 going to free the pool
Thu May 2 00:33:19 2002 mio.c:355 cur was equal to null
Thu May 2 00:33:19 2002 mio.c:279 write_dump writing data: <presence
from='escobal at jabber.cw.com/JabberIM'
to='escobal at jabber.cw.com'><status>Online</status><priority>1</priority>
<x xmlns='jabber:x:delay' from='escobal at jabber.cw.com/JabberIM'
stamp='20020502T00:33:18'/></presence>
Thu May 2 00:33:19 2002 mio.c:282 cur is not null
Thu May 2 00:33:19 2002 mio.c:284 the write pointer is not null
Thu May 2 00:33:19 2002 mio.c:287 all is ok for another write:
<presence from='escobal at jabber.cw.com/JabberIM'
to='escobal at jabber.cw.com'><status>Online</status><priority>1</priority>
<x xmlns='jabber:x:delay' from='escobal at jabber.cw.com/JabberIM'
stamp='20020502T00:33:18'/></presence>
Thu May 2 00:33:19 2002 mio.c:288 state is 0
Thu May 2 00:33:19 2002 mio_ssl.c:187 Entering into _mio_ssl_write
Thu May 2 00:33:19 2002 mio_ssl.c:188 buf: <presence
from='escobal at jabber.cw.com/JabberIM'
to='escobal at jabber.cw.com'><status>Online</status><priority>1</priority>
<x xmlns='jabber:x:delay' from='escobal at jabber.cw.com/JabberIM'
stamp='20020502T00:33:18'/></presence>; count: 222
Thu May 2 00:33:19 2002 mio_ssl.c:215 The ssl state is OK
Thu May 2 00:33:19 2002 mio_ssl.c:217 ssl is not null
Thu May 2 00:33:19 2002 mio.c:295 completed the write
Thu May 2 00:33:19 2002 mio.c:311 going to check the value of len now:
222
Thu May 2 00:33:19 2002 mio.c:345 all done writing
Thu May 2 00:33:19 2002 mio.c:350 going to free the pool
Thu May 2 00:33:19 2002 mio.c:355 cur was equal to null
Thu May 2 00:33:19 2002 mio.c:279 write_dump writing data: <presence
from='longleyp at jabber.cw.com/Jabber Instant Messenger'
to='escobal at jabber.cw.com'><status>Gardening
</status><priority>1</priority><show>dnd</show><x xmlns='jabber:x:delay'
from='longleyp at jabber.cw.com/Jabber Instant Messenger'
stamp='20020501T08:29:08'/></presence>
Thu May 2 00:33:19 2002 mio.c:282 cur is not null
Thu May 2 00:33:19 2002 mio.c:284 the write pointer is not null
Thu May 2 00:33:19 2002 mio.c:287 all is ok for another write:
<presence from='longleyp at jabber.cw.com/Jabber Instant Messenger'
to='escobal at jabber.cw.com'><status>Gardening
</status><priority>1</priority><show>dnd</show><x xmlns='jabber:x:delay'
from='longleyp at jabber.cw.com/Jabber Instant Messenger'
stamp='20020501T08:29:08'/></presence>
Thu May 2 00:33:19 2002 mio.c:288 state is 0
Thu May 2 00:33:19 2002 mio_ssl.c:187 Entering into _mio_ssl_write
Thu May 2 00:33:19 2002 mio_ssl.c:188 buf: <presence
from='longleyp at jabber.cw.com/Jabber Instant Messenger'
to='escobal at jabber.cw.com'><status>Gardening
</status><priority>1</priority><show>dnd</show><x xmlns='jabber:x:delay'
from='longleyp at jabber.cw.com/Jabber Instant Messenger'
stamp='20020501T08:29:08'/></presence>; count: 276
Thu May 2 00:33:19 2002 mio_ssl.c:215 The ssl state is OK
Thu May 2 00:33:19 2002 mio_ssl.c:217 ssl is not null
Then I do a kill -9 on the process and the following is printed.
Thu May 2 00:53:20 2002 dnsrv.c:155 dnsrv: Read error on
coprocess(198434): 0 Successful
Thu May 2 00:53:20 2002 dnsrv.c:169 DNSRV CHILD: out of loop.. exiting
normal
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://www.jabber.org/jdev/attachments/20020501/9bc58a7c/attachment-0002.htm>
More information about the JDev
mailing list