Connection pool jdbc and listener logfile content

From: Radoulov, Dimitre <cichomitiko_at_gmail.com>
Date: Tue, 07 Dec 2010 09:55:18 +0100
Message-ID: <idkspn$krh$1_at_news.eternal-september.org>


Hi all,

Environment

Various applications that use jdbc connection pool: WebLogic 8 (and higher) and Tomcat 6 application servers, various versions of Oracle Database (from 9.2.0.7 to 10.2.0.4) on various platforms (RHEL 5.5, Solaris 9, Solari 10 etc).

I'm trying to understand the meaning of the following entries in the listener log file (notice the frequency):

07-DEC-2010 09:32:30 *
(CONNECT_DATA=(SID=<my_sid>)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=<my_user>)))
* (ADDRESS=(PROTOCOL=tcp)(HOST=<my_host>)(PORT=59576)) * establish * <my_sid> * 0
07-DEC-2010 09:32:30 *
(CONNECT_DATA=(SID=<my_sid>)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=<my_user>)))
* (ADDRESS=(PROTOCOL=tcp)(HOST=<my_host>)(PORT=59578)) * establish * <my_sid> * 0
07-DEC-2010 09:32:30 *
(CONNECT_DATA=(SID=<my_sid>)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=<my_user>)))
* (ADDRESS=(PROTOCOL=tcp)(HOST=<my_host>)(PORT=59577)) * establish * <my_sid> * 0
07-DEC-2010 09:32:30 *
(CONNECT_DATA=(SID=<my_sid>)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=<my_user>)))
* (ADDRESS=(PROTOCOL=tcp)(HOST=<my_host>)(PORT=59579)) * establish * <my_sid> * 0
07-DEC-2010 09:32:30 *
(CONNECT_DATA=(SID=<my_sid>)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=<my_user>)))
* (ADDRESS=(PROTOCOL=tcp)(HOST=<my_host>)(PORT=59580)) * establish * <my_sid> * 0
07-DEC-2010 09:32:30 *
(CONNECT_DATA=(SID=<my_sid>)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=<my_user>)))
* (ADDRESS=(PROTOCOL=tcp)(HOST=<my_host>)(PORT=59581)) * establish * <my_sid> * 0
07-DEC-2010 09:32:30 *
(CONNECT_DATA=(SID=<my_sid>)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=<my_user>)))
* (ADDRESS=(PROTOCOL=tcp)(HOST=<my_host>)(PORT=59583)) * establish * <my_sid> * 0
07-DEC-2010 09:32:30 *
(CONNECT_DATA=(SID=<my_sid>)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=<my_user>)))
* (ADDRESS=(PROTOCOL=tcp)(HOST=<my_host>)(PORT=59582)) * establish * <my_sid> * 0
07-DEC-2010 09:32:32 *
(CONNECT_DATA=(SID=<my_sid>)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=<my_user>)))
* (ADDRESS=(PROTOCOL=tcp)(HOST=<my_host>)(PORT=59589)) * establish * <my_sid> * 0
07-DEC-2010 09:32:43 *
(CONNECT_DATA=(SID=<my_sid>)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=<my_user>)))
* (ADDRESS=(PROTOCOL=tcp)(HOST=<my_host>)(PORT=59600)) * establish * <my_sid> * 0
07-DEC-2010 09:32:43 *
(CONNECT_DATA=(SID=<my_sid>)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=<my_user>)))
* (ADDRESS=(PROTOCOL=tcp)(HOST=<my_host>)(PORT=59601)) * establish * <my_sid> * 0

All those applications use connection pools, v$session.logon_time reflect the time the connection pool was activated (usually tha application server start time) and the expected number of connections.

So I'm trying to understand what those frequent entries in the listener log represent.

Are these fresh new connections (I suppose they aren't) or they just represent the regular traffic that passes through the existing connections of the connection pool (if this is not the case, I don't understand why the port is changing (I know the listener redirects the client to a free port during the initial handshake, but I don't understand why this is happening after the connection pool is already up)

Could this be sort of heart beat that doesn't use the connection pool?

Unfortunately, in this case, auditing is disabled for application users so I don't have details in dba_audit_trail.

These are some numbers from this particular logfile:

$ tail -1000 listener_<my_sid>.log | awk 'END {

     for (i in count)
   if (count[i] > 10)
     print i, count[i]
}

   /__jdbc__/ {

     sub(/:[^:]*$/, x, $2)
     count[$2]++

   }'
09:14 13
09:17 32
08:45 14
09:19 12
08:49 13
09:32 33
09:35 20
09:37 17
09:38 29
08:30 35
09:03 13
09:05 13
08:33 13
08:51 11
09:24 28


The records are out of order but this is not relevant here, what I'm trying to understand the meaning of these 35 entries per minute.

Thank you
Dimitre

P.S. I posted the same question on another forum, so for some users it's a duplicate, sorry. Received on Tue Dec 07 2010 - 02:55:18 CST

Original text of this message