[OpenSIPS-Devel] [ opensips-Bugs-3576351 ] sip_trace module bug

SourceForge.net noreply at sourceforge.net
Mon Oct 22 17:52:56 CEST 2012


Bugs item #3576351, was opened at 2012-10-11 07:53
Message generated for change (Comment added) made by dmsanders
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=1086410&aid=3576351&group_id=232389

Please note that this message will contain a full copy of the comment thread,
including the initial issue submission, for this request,
not just the latest update.
Category: modules
Group: 1.8.x
Status: Open
Resolution: None
Priority: 5
Private: No
Submitted By: Dragos Oancea (dragosoancea)
Assigned to: Bogdan-Andrei Iancu (bogdan_iancu)
Summary: sip_trace module bug

Initial Comment:
Hi

The siptrace module reports a wrong value in the `fromip` field of the sip_trace table. 

For example , for this INVITE, coming from tls:80.187.x.x:62510 , I would expect the value "tls:80.187.x.x:62510" to be added in the `fromip` field,
but it's adding "tls:80.187.x.x:625" instead . It's missing two digits from the port value.
Also , sometimes it would put its local port (in my case 5061) instead of the remote port in the `fromip` or `toip` fields.


INVITE sips:+49170738xxxx at sip.domain.com SIP/2.0
Call-Id: c64e6615c79ab23501ad13f2e1a58918 at 10.77.26.75
CSeq: 1 INVITE
Via: SIP/2.0/TLS 10.77.26.75:59076;branch=z9hG4bK127109c14cd3b59c9ef9909b737982ab
Max-Forwards: 70
From: "+491713xxxxx" <sips:username at sip.domain.com>;tag=yRkyOWfbq
To: <sips:+4917073xxxxx at sip.domain.com>
Contact: <sips:00xxxx at 80.187.x.x:62510;transport=tls>
Allow: ACK,BYE
User-Agent: SomeUserAgent
Content-Type: application/sdp
Content-Length: 138

v=0
o=- 1349965870484 1349965870484 IN IP4 10.77.26.75
s=-
c=IN IP4 10.77.26.75
t=0 0
m=audio 37566 RTP/AVP 0
a=rtpmap:0 PCMU/8000



The problem was observed with opensips 1.8.1-tls and opensips-1.7.2-tls . 

Cheers,
Dragos



----------------------------------------------------------------------

Comment By: David Sanders (dmsanders)
Date: 2012-10-22 08:52

Message:
I believe it occurs for both requests and replies for me as well.

- David

----------------------------------------------------------------------

Comment By: Dragos Oancea (dragosoancea)
Date: 2012-10-22 08:17

Message:
I see the error for `fromip` , direction `in`  for both requests and
replies. 22 characters.
I never saw a space in that field, but maybe my IPs are longer.

Cheers,
Dragos

----------------------------------------------------------------------

Comment By: Bogdan-Andrei Iancu (bogdan_iancu)
Date: 2012-10-20 01:00

Message:
What about the type of SIP requests - do you see the err for requests or
for replies (or both ?) ?

Regards,
Bogdan

----------------------------------------------------------------------

Comment By: David Sanders (dmsanders)
Date: 2012-10-19 16:24

Message:
I only see it occurring on direction = 'in'.

In addition, it only affects the fromip field. It seems to be truncated to
22 characters.

If there is a space in the port number it is only if the fromip was less
than 22 characters. For example "udp:xx.xxx.x.xx:5060 1" is a pattern I see
a lot. 1 seems to be the most common extra character, but I also see 0, 4,
7, 9, etc.

----------------------------------------------------------------------

Comment By: Bogdan-Andrei Iancu (bogdan_iancu)
Date: 2012-10-19 09:08

Message:
Ok, last question - have you noticed a pattern on what kind of records have
bogus port values ? like request, in or out, ? or maybe for replies ? It
will help me to dig into the right code.

Regards,
Bogdan

----------------------------------------------------------------------

Comment By: David Sanders (dmsanders)
Date: 2012-10-19 00:31

Message:
I've also encountered this issue as described, with opensips 1.8.0-tls.

In addition to the described case, I've seen times where the field will
look like "sip:80.187.x.x:625 1", with a space present in the port number.
This seems to suggest it isn't truncation.

----------------------------------------------------------------------

Comment By: Dragos Oancea (dragosoancea)
Date: 2012-10-17 01:35

Message:
Hi Bogdan,

No , I am not using that feature.

Regards,
Dragos

----------------------------------------------------------------------

Comment By: Bogdan-Andrei Iancu (bogdan_iancu)
Date: 2012-10-16 10:40

Message:
Are you using buffering and merging for multiple INSERTs ?
      http://www.opensips.org/Resources/DocsCoreFcn18#toc69

Regards,
Bogdan

----------------------------------------------------------------------

Comment By: Dragos Oancea (dragosoancea)
Date: 2012-10-15 05:32

Message:

mysql> desc sip_trace ;
+-------------+------------------+------+-----+---------------------+----------------+
| Field       | Type             | Null | Key | Default             | Extra
         |
+-------------+------------------+------+-----+---------------------+----------------+
| id          | int(10) unsigned | NO   | PRI | NULL                |
auto_increment |
| date        | datetime         | NO   | MUL | 1900-01-01 00:00:01 |      
         |
| callid      | varchar(255)     | NO   | MUL |                     |      
         |
| traced_user | varchar(128)     | NO   | MUL |                     |      
         |
| msg         | text             | NO   |     | NULL                |      
         |
| method      | varchar(50)      | NO   |     |                     |      
         |
| status      | varchar(128)     | NO   |     |                     |      
         |
| fromip      | varchar(50)      | NO   | MUL |                     |      
         |
| toip        | varchar(50)      | NO   |     |                     |      
         |
| fromtag     | varchar(64)      | NO   |     |                     |      
         |
| direction   | varchar(4)       | NO   |     |                     |      
         |
| time_stamp  | timestamp        | NO   |     | CURRENT_TIMESTAMP   |      
         |
+-------------+------------------+------+-----+---------------------+----------------+
12 rows in set (0.01 sec)

They are varchar(50) , there should be enough space.
Also , sometimes the same ip:port pair is inserted correctly - for example
it could we wrong for the received INVITE, but it could be correct for the
relayed BYE .

 


----------------------------------------------------------------------

Comment By: Bogdan-Andrei Iancu (bogdan_iancu)
Date: 2012-10-15 05:04

Message:
Could you check the table format ? Do "desc siptrace" and see what are the
sizes of the fromip and toip fields in the table - maybe the truncating is
done by db.

----------------------------------------------------------------------

Comment By: Dragos Oancea (dragosoancea)
Date: 2012-10-15 04:27

Message:
Hi Bogdan,


INVITE sips:+4917133xxxxx at sip.domain.com SIP/2.0
Call-Id: 6484f90259156c8d702a1cae0eb49f27 at 10.208.83.156
CSeq: 1 INVITE
Via: SIP/2.0/TLS
10.208.83.156:53912;branch=z9hG4bK2929012bef3d8abb931df26bd8fa498c
Max-Forwards: 70
From: "+4917073xxxxx" <sips:xxxxx at sis.secusmart.com>;tag=IhJICbbyh
To: <sips:+4917133xxxxx at sip.domain.com>
Contact: <sips:xxxxxx at 80.187.x.x:52316;transport=tls>
Allow: ACK,BYE
User-Agent: SomeUserAgent
Content-Type: application/sdp
Content-Length: 142

v=0
o=- 1350298945023 1350298945023 IN IP4 10.208.83.156
s=-
c=IN IP4 10.208.83.156
t=0 0
m=audio 58639 RTP/AVP 0
a=rtpmap:0 PCMU/8000

| INVITE   |        | tls:80.187.x.x:5231 | tls:212.162.x.x:5061   |
IhJICbbyh | in        | 2012-10-15 13:02:24 |



CRITICAL:siptrace:sip_trace: xXx to ip is [tls:212.162.x.x:5061]
CRITICAL:siptrace:sip_trace: xXx from ip is [tls:80.187.x.x:52316]


The log entries (printed with the patch you provided) look correct, the
`fromip` and `toip` fields are showing truncated values in the sip_trace
table for most of the request and replies.

Cheers,
Dragos


----------------------------------------------------------------------

Comment By: Bogdan-Andrei Iancu (bogdan_iancu)
Date: 2012-10-12 06:30

Message:
Dragos, apply this patch -> it will print to logs (on critical level) the
calculated FROMIP and TOIP values. When you find bogus entries in siptrace,
you can try to correlate with the log to see if the values from logs are
also truncated.

Thanks and regards,
Bogdan

----------------------------------------------------------------------

Comment By: Dragos Oancea (dragosoancea)
Date: 2012-10-12 04:51

Message:
Hi

Yes, it happens very often,I don't know why . Sometime it puts the correct
values into the fields (for messages within the same dialog I could see
some entries  -requests or replies - added with the correct port , but 
some are missing one or two digits ),

If you provide the patch I'll apply it.

Cheers,
Dragos

----------------------------------------------------------------------

Comment By: Bogdan-Andrei Iancu (bogdan_iancu)
Date: 2012-10-12 04:22

Message:
Can you reproduce that? if so, I will provide a small patch to print some
extra logs - the idea is to see if the truncation comes from the siptrace
or the mysql module 

Regards,
Bogdan

----------------------------------------------------------------------

You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=1086410&aid=3576351&group_id=232389



More information about the Devel mailing list