dtrace discuss - Nov 2006 - DTrace: Printing pid of the process when tcpListenDrop is incremented

IHAC who is seeing high number of tcpListenDrop events. There are
multiple servers are running on the system. He likes to know the pid of
the process that has its listen backlog full and responsible for
triggering the tcpListenDrop event. tcpListenDrop counter is logged in


tcp_conn_request(void *arg, mblk_t *mp, void *arg2)
{
....
if (tcp->tcp_conn_req_cnt_q >= tcp->tcp_conn_req_max) {
                mutex_exit(&tcp->tcp_eager_lock);
                TCP_STAT(tcp_listendrop);  <<<<<<
                BUMP_MIB(&tcp_mib, tcpListenDrop);
...
}

My question is how one can get pid from conn_t or tcp_t structure so
that we know which process backlog size execeeds the max size.

#!/usr/sbin/dtrace -s

#pragma D option quiet

fbt:ip:tcp_conn_request:entry
{
        self->connp = (conn_t *)arg0;
        self->tcp   = (tcp_t *)self->connp->conn_tcp;


@backlog[self->tcp->tcp_conn_req_cnt_q,self->tcp->tcp_conn_req_max]=count();

printf("\ntcp_conn_req_cnt_q: %d\n",
self->tcp->tcp_conn_req_cnt_q);
printf("\ntcp_conn_req_max: %d\n", self->tcp->tcp_conn_req_max);

}

Thanks,
-- 
Amer Ather	
PTS-KERNEL     			
amer.ather at Sun.COM		
408-276-9780 (x19780)				
Pager: 888-242-1324
email-pager: 8882421324 at archwireless.net

	" In theory, there is no difference between theory and practice,
	  but in practice, there is."
					-Jan L.A. van de Snepscheut

Amer Ather writes:
> IHAC who is seeing high number of tcpListenDrop events. There are
> multiple servers are running on the system. He likes to know the pid of
> the process that has its listen backlog full and responsible for
> triggering the tcpListenDrop event. tcpListenDrop counter is logged in
You can get the pid of the process that opened the socket by looking
at tcp_cpid.  However, since it''s possible for a process to fork --
causing multiple processes to hold a single socket open -- and for the
original owner to exit, there''s no guarantee that this value is
meaningful.

What you really want is to find _all_ processes holding a given socket
open.  That''s a substantially harder job.

-- 
James Carlson, KISS Network                    <james.d.carlson at
sun.com>
Sun Microsystems / 1 Network Drive         71.232W   Vox +1 781 442 2084
MS UBUR02-212 / Burlington MA 01803-2757   42.496N   Fax +1 781 442 1677

conn_t has the cred  structure conn_cred.

Rao.


Amer Ather wrote:
> IHAC who is seeing high number of tcpListenDrop events. There are
> multiple servers are running on the system. He likes to know the pid of
> the process that has its listen backlog full and responsible for
> triggering the tcpListenDrop event. tcpListenDrop counter is logged in
>
>
> tcp_conn_request(void *arg, mblk_t *mp, void *arg2)
> {
> ....
> if (tcp->tcp_conn_req_cnt_q >= tcp->tcp_conn_req_max) {
>                 mutex_exit(&tcp->tcp_eager_lock);
>                 TCP_STAT(tcp_listendrop);  <<<<<<
>                 BUMP_MIB(&tcp_mib, tcpListenDrop);
> ...
> }
>
> My question is how one can get pid from conn_t or tcp_t structure so
> that we know which process backlog size execeeds the max size.
>
> #!/usr/sbin/dtrace -s
>
> #pragma D option quiet
>
> fbt:ip:tcp_conn_request:entry
> {
>         self->connp = (conn_t *)arg0;
>         self->tcp   = (tcp_t *)self->connp->conn_tcp;
>
>
>
@backlog[self->tcp->tcp_conn_req_cnt_q,self->tcp->tcp_conn_req_max]=count();
>
> printf("\ntcp_conn_req_cnt_q: %d\n",
self->tcp->tcp_conn_req_cnt_q);
> printf("\ntcp_conn_req_max: %d\n",
self->tcp->tcp_conn_req_max);
>
> }
>
> Thanks,
>

Rao Shoaib writes:
> conn_t has the cred  structure conn_cred.
Cred != PID.

-- 
James Carlson, KISS Network                    <james.d.carlson at
sun.com>
Sun Microsystems / 1 Network Drive         71.232W   Vox +1 781 442 2084
MS UBUR02-212 / Burlington MA 01803-2757   42.496N   Fax +1 781 442 1677

James Carlson wrote:
> Rao Shoaib writes:
>   
>> conn_t has the cred  structure conn_cred.
>>     
>
> Cred != PID.
>
>   
Yup. Sorry  I confused pid with uid.


Rao.

I think printing "tcp_cpid" is sufficient for finding server processes
causing tcpListenDrop events.

@backlog[self->tcp->tcp_cpid,self->tcp->tcp_conn_req_cnt_q,self->tcp->tcp_conn_req_max]=count();
..

printa("PID:%d\ttcp_conn_req_cnt_q/tcp_conn_req_max: %d/%d  Number of
times:%@d", at backlog);

Running the script provide us:

PID:758 tcp_conn_req_cnt_q/tcp_conn_req_max: 0/16  Number of times:3


 % pgrep inetd
758

Thanks,
Amer.

Rao Shoaib wrote On 11/16/06 01:20 PM,:
> James Carlson wrote:
> 
>>Rao Shoaib writes:
>>  
>>
>>>conn_t has the cred  structure conn_cred.
>>>    
>>
>>Cred != PID.
>>
>>  
> 
> Yup. Sorry  I confused pid with uid.
> 
> 
> Rao.
> 
> 

-- 
Amer Ather	
PTS-KERNEL     			
amer.ather at Sun.COM		
408-276-9780 (x19780)				
Pager: 888-242-1324
email-pager: 8882421324 at archwireless.net

	" In theory, there is no difference between theory and practice,
	  but in practice, there is."
					-Jan L.A. van de Snepscheut

Amer Ather wrote:
> I think printing "tcp_cpid" is sufficient for finding server
processes
> causing tcpListenDrop events.
> 
>
@backlog[self->tcp->tcp_cpid,self->tcp->tcp_conn_req_cnt_q,self->tcp->tcp_conn_req_max]=count();
> ..
> 
> printa("PID:%d\ttcp_conn_req_cnt_q/tcp_conn_req_max: %d/%d  Number of
> times:%@d", at backlog);
> 
> Running the script provide us:
> 
> PID:758 tcp_conn_req_cnt_q/tcp_conn_req_max: 0/16  Number of times:3
> 
> 
>  % pgrep inetd
> 758
Arghh..  And you can''t even adjust the listen backlog for inetd in S10
-
see 6303365.

The "-l <backlog>" option was undocumented in inetd(1M) in S9
and
earlier - in the conversion to SMF, it was not made into a property. 
And the command line option no longer exists.

Good to add an SR to 6303365, I think.

Not that it is a cure all, but a listen backlog more than the current 
hardcoded value of 10 would probably help.

- Neil
> Thanks,
> Amer.
> 
> Rao Shoaib wrote On 11/16/06 01:20 PM,:
> 
>>James Carlson wrote:
>>
>>
>>>Rao Shoaib writes:
>>> 
>>>
>>>
>>>>conn_t has the cred  structure conn_cred.
>>>>   
>>>
>>>Cred != PID.
>>>
>>> 
>>
>>Yup. Sorry  I confused pid with uid.
>>
>>
>>Rao.
>>
>>
> 
> 
> 

-- 
Neil Putnam
Systems Technology Service Center / Network
Global Sales and Services - Sun Microsystems, Inc.
Broomfield, Colorado  USA
(303) 464-4648 x50648

Neil,

Yes, I noticed that the listen backlog for inetd is very small. However,
  customer issue is not related to inetd. I was using ftp and telnet in
lab to test the script.

Amer
Neil Putnam wrote On 11/16/06 02:07 PM,:
> Amer Ather wrote:
> 
>>I think printing "tcp_cpid" is sufficient for finding server
processes
>>causing tcpListenDrop events.
>>
>>@backlog[self->tcp->tcp_cpid,self->tcp->tcp_conn_req_cnt_q,self->tcp->tcp_conn_req_max]=count();
>>..
>>
>>printa("PID:%d\ttcp_conn_req_cnt_q/tcp_conn_req_max: %d/%d  Number
of
>>times:%@d", at backlog);
>>
>>Running the script provide us:
>>
>>PID:758 tcp_conn_req_cnt_q/tcp_conn_req_max: 0/16  Number of times:3
>>
>>
>> % pgrep inetd
>>758
> 
> 
> Arghh..  And you can''t even adjust the listen backlog for inetd in
S10 -
> see 6303365.
> 
> The "-l <backlog>" option was undocumented in inetd(1M) in
S9 and
> earlier - in the conversion to SMF, it was not made into a property. 
> And the command line option no longer exists.
> 
> Good to add an SR to 6303365, I think.
> 
> Not that it is a cure all, but a listen backlog more than the current 
> hardcoded value of 10 would probably help.
> 
> - Neil
> 
> 
>>Thanks,
>>Amer.
>>
>>Rao Shoaib wrote On 11/16/06 01:20 PM,:
>>
>>
>>>James Carlson wrote:
>>>
>>>
>>>
>>>>Rao Shoaib writes:
>>>>
>>>>
>>>>
>>>>
>>>>>conn_t has the cred  structure conn_cred.
>>>>>  
>>>>
>>>>Cred != PID.
>>>>
>>>>
>>>
>>>Yup. Sorry  I confused pid with uid.
>>>
>>>
>>>Rao.
>>>
>>>
>>
>>
>>
> 
> 

-- 
Amer Ather	
PTS-KERNEL     			
amer.ather at Sun.COM		
408-276-9780 (x19780)				
Pager: 888-242-1324
email-pager: 8882421324 at archwireless.net

	" In theory, there is no difference between theory and practice,
	  but in practice, there is."
					-Jan L.A. van de Snepscheut

Amer Ather wrote:
> Neil,
> 
> Yes, I noticed that the listen backlog for inetd is very small. However,
>   customer issue is not related to inetd. I was using ftp and telnet in
> lab to test the script.
> 
> Amer
Oh, umm.... never mind!  ;)
- Neil
> Neil Putnam wrote On 11/16/06 02:07 PM,:
> 
>>Amer Ather wrote:
>>
>>
>>>I think printing "tcp_cpid" is sufficient for finding
server processes
>>>causing tcpListenDrop events.
>>>
>>>@backlog[self->tcp->tcp_cpid,self->tcp->tcp_conn_req_cnt_q,self->tcp->tcp_conn_req_max]=count();
>>>..
>>>
>>>printa("PID:%d\ttcp_conn_req_cnt_q/tcp_conn_req_max: %d/%d 
Number of
>>>times:%@d", at backlog);
>>>
>>>Running the script provide us:
>>>
>>>PID:758 tcp_conn_req_cnt_q/tcp_conn_req_max: 0/16  Number of times:3
>>>
>>>
>>>% pgrep inetd
>>>758
>>
>>
>>Arghh..  And you can''t even adjust the listen backlog for inetd
in S10 -
>>see 6303365.
>>
>>The "-l <backlog>" option was undocumented in inetd(1M)
in S9 and
>>earlier - in the conversion to SMF, it was not made into a property. 
>>And the command line option no longer exists.
>>
>>Good to add an SR to 6303365, I think.
>>
>>Not that it is a cure all, but a listen backlog more than the current 
>>hardcoded value of 10 would probably help.
>>
>>- Neil