[Search for users]
[Overall Top Noters]
[List of all Conferences]
[Download this site]
| Title: | Discussion of CICS technical issues |
|
| Moderator: | IOSG::SMITHF |
|
| Created: | Mon Mar 13 1995 |
| Last Modified: | Fri Jun 06 1997 |
| Last Successful Update: | Fri Jun 06 1997 |
| Number of topics: | 192 |
| Total number of notes: | 680 |
174.0. "problem with CICS EPI and memory leaks" by NETRIX::"[email protected]" (Ricardo Lopez Cencerrado) Fri Mar 14 1997 17:36
I am developing a daemon process which serves as a gateway between a tcp
client
and CICS OSF using the EPI interface. the client sends the daemon the
transaction
and receives back the host answer.
The daemon is a multithreaded server, which generates two threads for every
conection. One attending the client connection and the other taking care of
the
EPI events received.
When the daemon runs with up to four concurrent conections ( 8 client related
threads) the daemon behaves fine. However, when more than 4 connections are
used the daemon shows memory leaks.
This is the transcript of a test with 4 connections and 8001 transactios per
connection. The daemon process is hstcom.test.14-03-97:
# ps aux | grep hstcom
root 1687 0.0 0.1 248K 72K ttyp8 S + 16:25:33 0:00.01 grep
hstcom
ricardo 1684 0.0 7.9 22.2M 4.9M ttyp2 S + 16:24:41 0:00.74
hstcom.test.14-3-97
# echo "that was the size with no activity"
that was the size with no activity
# echo "starting now"
starting now
# ps aux | grep hstcom "
ricardo 1684 6.0 2.0 23.8M 1.2M ttyp2 S + 16:24:41 0:02.05
hstcom.test.14-3-97
root 1694 0.0 0.1 248K 72K ttyp8 S + 16:27:09 0:00.01 grep
hstcom
# ps aux | grep hstcom
ricardo 1684 9.0 2.0 23.8M 1.2M ttyp2 S + 16:24:41 0:15.39
hstcom.test.14-3-97
root 1697 0.0 0.1 248K 72K ttyp8 S + 16:29:23 0:00.01 grep
hstcom
now with 2000 trans/client
# ps aux | grep hstcom
ricardo 1684 9.0 2.0 23.8M 1.2M ttyp2 S + 16:24:41 0:20.05
hstcom.test.14-3-97
root 1699 0.0 0.1 248K 72K ttyp8 S + 16:30:07 0:00.01 grep
hstcom
# echo "now with 3000 trans/client"
now with 3000 trans/client
# ps aux | grep hstcom
ricardo 1684 8.0 2.0 23.8M 1.2M ttyp2 S + 16:24:41 0:36.30
hstcom.test.14-3-97
root 1701 0.0 0.1 248K 72K ttyp8 S + 16:32:41 0:00.01 grep
hstcom
# echo "now with 4000 trans/client"
now with 4000 trans/client
# ps aux | grep hstcom
ricardo 1684 8.0 2.0 23.8M 1.2M ttyp2 S + 16:24:41 0:38.58
hstcom.test.14-3-97
root 1703 0.0 0.1 248K 72K ttyp8 S + 16:33:05 0:00.01 grep
hstcom
# echo "now with 5000 trans/client"
now with 5000 trans/client
# ps aux | grep hstcom
ricardo 1684 9.0 2.0 23.8M 1.2M ttyp2 S + 16:24:41 0:47.64
hstcom.test.14-3-97
root 1705 0.0 0.1 248K 72K ttyp8 S + 16:34:34 0:00.01 grep
hstcom
# echo "now with 6000 trans/client"
now with 6000 trans/client
# ps aux | grep hstcom
ricardo 1684 9.0 2.0 23.8M 1.2M ttyp2 S + 16:24:41 0:56.86
hstcom.test.14-3-97
root 1707 0.0 0.1 248K 72K ttyp8 S + 16:36:01 0:00.01 grep
hstcom
# echo "now with 7000 trans/client"
now with 7000 trans/client
# ps aux | grep hstcom
ricardo 1684 9.0 2.0 23.8M 1.2M ttyp2 S + 16:24:41 1:05.93
hstcom.test.14-3-97
root 1709 0.0 0.1 248K 72K ttyp8 S + 16:37:27 0:00.01 grep
hstcom
# echo "now with all8000 tran/client"
8000 trans/client done"
now with all 8000 trans/client done
# ps aux | grep hstcom
ricardo 1684 0.0 2.0 23.8M 1.2M ttyp2 S + 16:24:41 1:15.29
hstcom.test.14-3-97
root 1711 0.0 0.1 248K 72K ttyp8 S + 16:39:06 0:00.01 grep
hstcom
# echo "now killing the process"
now killing the process
# ps aux | grep hstcom
ricardo 1684 0.0 2.5 23.8M 1.6M ttyp2 S + 16:24:41 1:15.34
hstcom.test.14-3-97
root 1714 0.0 0.1 248K 72K ttyp8 S + 16:46:10 0:00.01 grep
hstcom
# ps aux | grep hstcom "
root 1717 0.0 0.1 248K 72K ttyp8 S + 16:46:30 0:00.01 grep
hstcom
# exit
# exit
This is an example when using 8 connections (16 threads) and 4001 transactions
per connection. the daemon process is hstcom.test.9clientes :
# echo "now I run a server allowed to support 8 connections"
now I run a server allowed to support 8 connections
# echo "and run 4001 transaction in each one"
and run 4001 transaction in each one
# ps aux | grep hstcom
root 1589 0.0 0.1 248K 72K ttyp8 S + 13:31:32 0:00.01 grep
hstcom
ricardo 1582 0.0 5.5 25.3M 3.4M ttyp2 S + 13:27:57 0:01.44
hstcom.test.9clientes
# echo "now all threads are running -> no process size increase is allowed"
now all threads are running -> no process size increase is allowed
# ps aux | grep hstcom
ricardo 1582 9.0 4.0 26.1M 2.5M ttyp2 S + 13:27:57 0:08.10
hstcom.test.9clientes
root 1591 0.0 0.1 248K 72K ttyp8 S + 13:33:13 0:00.02 grep
hstcom
# ps aux | grep "hstcom.test"
ricardo 1582 9.0 4.3 26.3M 2.7M ttyp2 S + 13:27:57 0:10.55
hstcom.test.9clientes
root 1593 0.0 0.1 248K 72K ttyp8 S + 13:33:36 0:00.01 grep
hstcom.test
# echo "now we are at 500 trans/thread"
now we are at 500 trans/thread
# ps aux | grep "hstcom.test"
ricardo 1582 10.0 4.6 26.6M 2.9M ttyp2 S + 13:27:57 0:14.00
hstcom.test.9clientes
root 1595 0.0 0.1 248K 72K ttyp8 S + 13:34:05 0:00.01 grep
hstcom.test
# echo "now we are at 1000 trans/thread"
now we are at 1000 trans/thread
# ps aux | grep "hstcom.test"
ricardo 1582 9.0 6.2 27.6M 3.8M ttyp2 S + 13:27:57 0:27.52
hstcom.test.9clientes
root 1597 0.0 0.1 248K 72K ttyp8 S + 13:35:57 0:00.01 grep
hstcom.test
# echo "now we are at 2000 trans/thread"
now we are at 2000 trans/thread
# echo "now we are at 1500 trans/thread"
now we are at 1500 trans/thread
# ps aux | grep "hstcom.test"
ricardo 1582 10.0 6.9 28.1M 4.3M ttyp2 S + 13:27:57 0:34.52
hstcom.test.9clientes
root 1599 0.0 0.1 248K 72K ttyp8 S + 13:36:55 0:00.01 grep
hstcom.test
# echo "now we are at 2000 trans/thread"
now we are at 2000 trans/thread
# ps aux | grep "hstcom.test"
ricardo 1582 9.0 8.0 28.6M 5.0M ttyp2 S + 13:27:57 0:44.69
hstcom.test.9clientes
root 1602 0.0 0.1 248K 72K ttyp8 S + 13:38:19 0:00.01 grep
hstcom.test
# echo "now we are at 2500 trans/thread"
now we are at 2500 trans/thread
# ps aux | grep "hstcom.test"
ricardo 1582 8.0 9.1 29.3M 5.6M ttyp2 S + 13:27:57 0:54.02
hstcom.test.9clientes
root 1605 0.0 0.1 248K 72K ttyp8 S + 13:39:38 0:00.01 grep
hstcom.test
# echo "now we are at 3000 trans/thread
now we are at 3000 trans/thread
# ps aux | grep "hstcom.test"
ricardo 1582 9.0 10.3 30.1M 6.4M ttyp2 S + 13:27:57 1:04.92
hstcom.test.9clientes
root 1608 0.0 0.1 248K 72K ttyp8 S + 13:41:09 0:00.01 grep
hstcom.test
# echo "now we are at 3500 trans/thread"
now we are at 3500 trans/thread
# ^ps aux | grep "hstcom.test"
ricardo 1582 10.0 11.4 30.8M 7.0M ttyp2 S + 13:27:57 1:15.01
hstcom.test.9clientes
root 1611 0.0 0.1 248K 72K ttyp8 S + 13:42:35 0:00.01 grep
hstcom.test
# echo "now we ar 3500 trans/thread"
# echo "n 3500 trans//thread"
# echo "test en 3500 trans/hread"
# echo "test ended f3500 trans/thread"
or 400 transthread"
01 trans/thread"
test ended for 4001 trans/thread
# ps aux | grep "hstcom.test"
root 1613 0.0 0.1 248K 72K ttyp8 S + 13:44:33 0:00.01 grep
hstcom.test
ricardo 1582 0.0 7.5 31.4M 4.6M ttyp2 S + 13:27:57 1:25.01
hstcom.test.9clientes
# echo "total growth is 31.4M - 26.1M"
total growth is 31.4M - 26.1M
# echo "now sending new conection to end the server process "
now sending new conection to end the server process
# echo "killed ok"
killed ok
Both test have been repeated using an instrumented version with atom V2.29 for
DUnix 3.2x (actually DUnix 3.2G).
The leak output of the test with 4 connections and 8001 transactions per
connection is:
------------------------------------------------------------------------
------------------------------------------------------------------------
Searching for new leaks in heap after program exit
A total of 88413 bytes in 192 leaks were found:
56432 bytes in 59 leaks (including 22 super leaks) created at:
malloc libpthreads.so
----- -----
----- -----
----- -----
8193 bytes in 1 leak (including 1 super leak) created at:
malloc libpthreads.so
pc = 0x2448d6b4 libc.so
pc = 0x2448c8c0 libc.so
__gethostbyname libc.so
----- -----
----- -----
----- -----
7056 bytes in 49 leaks (including 9 super leaks) created at:
malloc libpthreads.so
cma__alloc_mem libpthreads.so
cma__vp_create libpthreads.so
cma__int_make_thread libpthreads.so
pthread_create libpthreads.so
----- -----
----- -----
----- -----
6192 bytes in 43 leaks (including 8 super leaks) created at:
malloc libpthreads.so
cma__alloc_mem libpthreads.so
cma__get_stack libpthreads.so
pc = 0x2421f0b8 libpthreads.so
cma__get_tcb libpthreads.so
pthread_create libpthreads.so
----- -----
----- -----
----- -----
3232 bytes in 1 leak (including 1 super leak) created at:
malloc libpthreads.so
cma__alloc_mem libpthreads.so
cma_key_create libpthreads.so
pthread_keycreate libpthreads.so
SupTM_pthread_ThreadAllocDataSlot libcicsco.so
CICS_EpiInitialize libcicsepico.so
main hstcom_c
1560 bytes in 4 leaks (including 4 super leaks) created at:
malloc libpthreads.so
TerSH_PackDetails libcicsco.so
TerEP_CallScheduler libcicsepico.so
TerEP_InstallTerm libcicsepico.so
CICS_EpiAddTerminal libcicsepico.so
AddTerminal hstcom_c
doEPIecho hstcom_c
ParentThreadMain hstcom_c
cma__thread_base libpthreads.so
800 bytes in 1 leak (including 1 super leak) created at:
malloc libpthreads.so
TerEP_Initialize libcicsepico.so
CICS_EpiInitialize libcicsepico.so
main hstcom_c
__start hstcom_c
656 bytes in 1 leak (including 1 super leak) created at:
malloc libpthreads.so
SupER_GetData libcicsco.so
pc = 0x6fefba44 libcicsco.so
SupER_StoreSymptom libcicsco.so
SupOS_LoadDLO2 libcicsco.so
CICS_EpiInitialize libcicsepico.so
main hstcom_c
__start hstcom_c
576 bytes in 4 leaks created at:
malloc libpthreads.so
cma__alloc_mem libpthreads.so
cma__vp_create libpthreads.so
cma__int_make_thread libpthreads.so
pthread_create libpthreads.so
AddTerminal hstcom_c
doEPIecho hstcom_c
ParentThreadMain hstcom_c
cma__thread_base libpthreads.so
576 bytes in 4 leaks created at:
malloc libpthreads.so
cma__alloc_mem libpthreads.so
cma__vp_create libpthreads.so
cma__int_make_thread libpthreads.so
pthread_create libpthreads.so
SupTM_pthread_ThreadCreate libcicsco.so
TerEP_RunInit libcicsepico.so
SupTM_pthread_ThreadCreate libcicsco.so
TerEP_RunInit libcicsepico.so
TerEP_InstallTerm libcicsepico.so
CICS_EpiAddTerminal libcicsepico.so
AddTerminal hstcom_c
doEPIecho hstcom_c
ParentThreadMain hstcom_c
cma__thread_base libpthreads.so
576 bytes in 4 leaks created at:
malloc libpthreads.so
cma__alloc_mem libpthreads.so
cma__get_stack libpthreads.so
pc = 0x2421f0b8 libpthreads.so
cma__get_tcb libpthreads.so
pthread_create libpthreads.so
SupTM_pthread_ThreadCreate libcicsco.so
TerEP_RunInit libcicsepico.so
TerEP_InstallTerm libcicsepico.so
CICS_EpiAddTerminal libcicsepico.so
AddTerminal hstcom_c
doEPIecho hstcom_c
ParentThreadMain hstcom_c
cma__thread_base libpthreads.so
576 bytes in 4 leaks created at:
malloc libpthreads.so
cma__alloc_mem libpthreads.so
cma__vp_create libpthreads.so
cma__int_make_thread libpthreads.so
pthread_create libpthreads.so
main hstcom_c
__start hstcom_c
432 bytes in 3 leaks (including 1 super leak) created at:
malloc libpthreads.so
cma__alloc_mem libpthreads.so
cma__get_stack libpthreads.so
pc = 0x2421f0b8 libpthreads.so
cma__get_tcb libpthreads.so
pthread_create libpthreads.so
AddTerminal hstcom_c
doEPIecho hstcom_c
ParentThreadMain hstcom_c
cma__thread_base libpthreads.so
432 bytes in 3 leaks (including 1 super leak) created at:
malloc libpthreads.so
cma__alloc_mem libpthreads.so
cma__get_stack libpthreads.so
pc = 0x2421f0b8 libpthreads.so
cma__get_tcb libpthreads.so
pthread_create libpthreads.so
main hstcom_c
__start hstcom_c
288 bytes in 2 leaks created at:
malloc libpthreads.so
cma__alloc_mem libpthreads.so
cma__get_attr libpthreads.so
pthread_attr_create libpthreads.so
SupTM_pthread_ThreadCreate libcicsco.so
TerEP_RunInit libcicsepico.so
TerEP_InstallTerm libcicsepico.so
CICS_EpiAddTerminal libcicsepico.so
AddTerminal hstcom_c
doEPIecho hstcom_c
ParentThreadMain hstcom_c
cma__thread_base libpthreads.so
836 bytes in 9 leaks (including 3 super leaks) below threshold of 1.0%
------------------------------------------------------------------------
------------------------------------------------------------------------
When running an instrumented version of the daemon with 8 connections and
4001 transactions per connection. the atom *3log file has a leak section
containing:
------------------------------------------------------------------------
------------------------------------------------------------------------
Searching for new leaks in heap after program exit
A total of 4766271 bytes in 12159 leaks were found:
4680780 bytes in 12002 leaks (including 12002 super leaks) created at:
malloc libpthreads.so
TerSH_PackDetails libcicsco.so
TerEP_CallScheduler libcicsepico.so
pc = 0x6fff379c libcicsepico.so
CICS_EpiStartTran libcicsepico.so
doEPI hstcom_c
doEPIecho hstcom_c
ParentThreadMain hstcom_c
cma__thread_base libpthreads.so
56264 bytes in 56 leaks (including 15 super leaks) created at:
malloc libpthreads.so
----- -----
----- -----
----- -----
29227 bytes in 101 leaks (including 33 super leaks) below threshold of 1.0%
------------------------------------------------------------------------
------------------------------------------------------------------------
The big leak in the second test seems to be the origin of the unexpected
size increase of the daemon.
The daemon does not explicity call *alloc* functions or use any form of
dynamic
memory allocation. Everything is stored in global arrays and all use of
dynamic
memory should then be related with thread operations, I guess.
As far as I understand, no special cleanup is required before or after
calling the CICS_EpiStartTran() function and the buffer required for this
function corresponds to a static array filled with the transaction. Am I doing
something wrong when using this EPI function or is some previous step
required?
I do not understand clearly the atom output file or how it relates to the
original source code. Is there some way to make its output clearer or to
point more specifically to the bigger leak?
Is this pointing some previous error in the code and why does it seem to
behave
in a different way when using 4 connections and when using 8 connections?
Should I also post this note in the Atom conference and/or the thread
conference to
get more insight?
The test system is DEC 3000-500 with 64MB RAM, Dunix 3.2G, CICS 2.1A and the
atom version is Atom V2.29 for DUnix 3.2G.
the compile command executed for generating the instrumented version is:
cd /usr/users/ricardo/project/hstcom/
make -f test3.mk hstcom_c.third
cc -c -taso -std1 -threads -I/usr/opt/cics/include -O2 cicserver.child-fork.c
ld /usr/ccs/lib/crt0.o -taso -call_shared -L/usr/opt/cics/lib -o hstcom_c
cicserver.child-
fork.o -lcicsepico -L/usr/opt/dce/usr/shlib/dce -lpthreads -lmach -lc_r -lc
atom hstcom_c -tool third -env threads -L/usr/opt/cics/lib
-L/usr/opt/dce/usr/shlib -all -
heapbase taso
The full Atom output can be set available. I have not posted the full output
because it is rather long. Any clue is wellcome.
Thanks in advance,
Ricardo Lopez Cencerrado.
[Posted by WWW Notes gateway]
| T.R | Title | User | Personal
Name | Date | Lines |
|---|
| 174.1 | Please raise as an offical problem - looks like a bug | MUFFIT::gerry | Gerry Reilly | Mon Mar 17 1997 13:50 | 16 |
| Hi,
Thank you for your clear description of the problem. I have discussed
the memory leak with one of the engineers in IBM Hursley. We believe
you may be seeing the same problem we have recently discovered during
the testing of V2.2. A fix to the V2.2 EPI memory leak is currently
being developed.
Please can you raise this leak as an official problem through MCS. They
will then enter the problem into IBM RETAIN problem system. This will
ensure that IBM checks that your problem is the same as the V2.2
EPI memory leak, and they can then develop a patch for V2.1A.
Thanks.
-gerry
|
| 174.2 | Workaround... | MUFFIT::gerry | Gerry Reilly | Tue Mar 18 1997 13:55 | 28 |
| RE: .0
It looks like you are hitting the same EPI leak that has been detected
in the V2.2 testing. A fix will in V2.2. If you need a fix for V2.1A
please enter a call with MCS and the fix will get back ported.
In the meantime there is a workaround.
The problem is caused by CICS not cleaning up correctly for transactions
that are started when this no listener thread in the RD.stanza) available
to service the transaction. The number of threads available to service
transactions is calculated using the MaxServer setting. Therefore the
workaround is, either-
1. Increasing the MaxServer in the RD.stanza
2. or set COMRL_RPCMULTIPLE=6 in the region's environment file. This is
an undocumented feature that will increase the number of threads
available
no_of_threads = MaxServer*COMRL_RPCMULTIPLE/2
The default value of COMRL_RPCMULTIPLE is 2. On V3.2x system do not set
COMRL_RPCMULTIPLE too high because this will result in very large numbers
of runnable threads and the resulting context switch rate will hurt
performance.
-gerry
|