6 Nov
2003
6 Nov
'03
2 a.m.
After playing around with the new firmware (and new SER cvs snapshot
0.8.12dev-22-tcp_aliases) I'm seeing some very strange behavior from SER
(ngrep trace follows):
U 1.1.19.48:1387 -> 1.1.16.55:5060
REGISTER sip:sip.test.net SIP/2.0..Via: SIP/2.0/UDP 1.1.19.48:1388..From:
<sip:6526@sip.test.net;user=phone>;tag=50886574..T
o: <sip:6526@sip.test.net;user=phone>..Call-ID: 4136319346@10.118.145.13..CSeq:
160 REGISTER..Contact: <sip:6526@1.1.19.48:
1388;user=phone;transport=udp>;expires=1800..User-Agent: Cisco ATA 186 v2.16.2
ata18x (030909a)..Content-Length: 0....
#
U 1.1.16.55:5060 -> 1.1.19.48:1388 25017@0:1480
...l....SIP/2.0 200 OK..Via: SIP/2.0/UDP 1.1.19.48:1388..From:
<sip:6526@sip.test.net;user=phone>;tag=50886574..To: <sip:65
26@sip.test.net;user=phone>;tag=0596aef19d8edd571cbf9827f60616bb.97c5..Call-ID:
4136319346@10.118.145.13..CSeq: 160 REGISTER..Co
ntact:
<sip:6526@1.1.19.48:1376;user=phone;transport=udp>;q=0.00;expires=30..Contact:
<sip:6526@1.1.19.48:1377;user=p
hone;transport=udp>;q=0.00;expires=56..Contact:
<sip:6526@1.1.19.48:1378;user=phone;transport=udp>;q=0.00;expires=517..Con
tact:
<sip:6526@1.1.19.48:1379;user=phone;transport=udp>;q=0.00;expires=527..Contact:
<sip:6526@1.1.19.48:1380;user=p
hone;transport=udp>;q=0.00;expires=652..Contact:
<sip:6526@1.1.19.48:1381;user=phone;transport=udp>;q=0.00;expires=780..Co
ntact:
<sip:6526@1.1.19.48:1382;user=phone;transport=udp>;q=0.00;expires=911..Contact:
<sip:6526@1.1.19.48:1383;user=
phone;transport=udp>;q=0.00;expires=1040..Contact:
<sip:6526@1.1.19.48:1385;user=phone;transport=udp>;q=0.00;expires=1303.
.Contact:
<sip:6526@1.1.19.48:1386;user=phone;transport=udp>;q=0.00;expires=1532..Contact:
<sip:6526@1.1.19.48:1387;u
ser=phone;transport=udp>;q=0.00;expires=1576..Contact:
<sip:6526@1.1.19.48:1388;user=phone;transport=udp>;q=0.00;expires=1
800..Server: Sip EXpress router (0.8.12dev-22-tcp_aliases (i386/linux))..Content-Length:
0..Warning: 392 sip.test.net:5060 "Nois
y feedback tells: pid=11260 req_src_ip=1.1.19.48 req_src_port=1387 in_uri=sip
This is repeated over and over and over again. This seems very bizzare to
me. ATAs with earlier firmware don't trigger this behavior. The only
thing that I can see different in the register request is the addition of
the tag in the From: line:
From: <sip:6526@sip.test.net;user=phone>;tag=50886574
whereas the old ATA registers with:
From: <sip:6526@sip.test.net;user=phone>
Any clues?? Thanks!!
- Mike
6 Nov
6 Nov
2:23 a.m.
The part which strikes me is the port number in contact.
The 200 returns lot of such contacts with ascending port
number. A possible explanation is that the ATA mistakenly
registers all over again contacts which are differnt
each timer (different port number). They are handled
as distinct contact by SER and that's why so many appear
in 200.
Maybe it happens because ATA does not think it received
the reply. It is a bad practice that it solicits replies
at a different port number (1388) than from which it sends
(1387).
Try sending replies to origination port by calling force_rport
from your script. Or even better, make your ATA receive
at port number from where it sends. (I don't know how, though.)
-jiri
At 01:00 AM 11/6/2003, Mike wrote:
After playing around with the new firmware (and new SER
cvs snapshot
0.8.12dev-22-tcp_aliases) I'm seeing some very strange behavior from SER
(ngrep trace follows):
U 1.1.19.48:1387 -> 1.1.16.55:5060
REGISTER sip:sip.test.net SIP/2.0..Via: SIP/2.0/UDP 1.1.19.48:1388..From:
<sip:6526@sip.test.net;user=phone>;tag=50886574..T
o: <sip:6526@sip.test.net;user=phone>..Call-ID: 4136319346@10.118.145.13..CSeq:
160 REGISTER..Contact: <sip:6526@1.1.19.48:
1388;user=phone;transport=udp>;expires=1800..User-Agent: Cisco ATA 186 v2.16.2
ata18x (030909a)..Content-Length: 0....
#
U 1.1.16.55:5060 -> 1.1.19.48:1388 25017@0:1480
...l....SIP/2.0 200 OK..Via: SIP/2.0/UDP 1.1.19.48:1388..From:
<sip:6526@sip.test.net;user=phone>;tag=50886574..To: <sip:65
26@sip.test.net;user=phone>;tag=0596aef19d8edd571cbf9827f60616bb.97c5..Call-ID:
4136319346@10.118.145.13..CSeq: 160 REGISTER..Co
ntact:
<sip:6526@1.1.19.48:1376;user=phone;transport=udp>;q=0.00;expires=30..Contact:
<sip:6526@1.1.19.48:1377;user=p
hone;transport=udp>;q=0.00;expires=56..Contact:
<sip:6526@1.1.19.48:1378;user=phone;transport=udp>;q=0.00;expires=517..Con
tact:
<sip:6526@1.1.19.48:1379;user=phone;transport=udp>;q=0.00;expires=527..Contact:
<sip:6526@1.1.19.48:1380;user=p
hone;transport=udp>;q=0.00;expires=652..Contact:
<sip:6526@1.1.19.48:1381;user=phone;transport=udp>;q=0.00;expires=780..Co
ntact:
<sip:6526@1.1.19.48:1382;user=phone;transport=udp>;q=0.00;expires=911..Contact:
<sip:6526@1.1.19.48:1383;user=
phone;transport=udp>;q=0.00;expires=1040..Contact:
<sip:6526@1.1.19.48:1385;user=phone;transport=udp>;q=0.00;expires=1303.
.Contact:
<sip:6526@1.1.19.48:1386;user=phone;transport=udp>;q=0.00;expires=1532..Contact:
<sip:6526@1.1.19.48:1387;u
ser=phone;transport=udp>;q=0.00;expires=1576..Contact:
<sip:6526@1.1.19.48:1388;user=phone;transport=udp>;q=0.00;expires=1
800..Server: Sip EXpress router (0.8.12dev-22-tcp_aliases (i386/linux))..Content-Length:
0..Warning: 392 sip.test.net:5060 "Nois
y feedback tells: pid=11260 req_src_ip=1.1.19.48 req_src_port=1387 in_uri=sip
This is repeated over and over and over again. This seems very bizzare to
me. ATAs with earlier firmware don't trigger this behavior. The only
thing that I can see different in the register request is the addition of
the tag in the From: line:
From: <sip:6526@sip.test.net;user=phone>;tag=50886574
whereas the old ATA registers with:
From: <sip:6526@sip.test.net;user=phone>
Any clues?? Thanks!!
- Mike
_______________________________________________
Serusers mailing list
serusers(a)lists.iptel.org
http://lists.iptel.org/mailman/listinfo/serusers
--
Jiri Kuthan http://iptel.org/~jiri/
6:26 a.m.
I think I've figured out most of the weirdness...
The ports are going up sequentially because the ATA is behind NAT, and
each time it registers it uses the next port up...
It looks like with the new ATA firmware the cisco doesn't remove the old
registrations properly anymore. The release note suggests that instead of
doing removing Contact: * it's supposed to remove only the contacts it
thinks are registered, but then it look like it removes anything at all.
So the list of contacts for 6526(a)sip.test.net keeps growing and growing
until eventually there are dozens of them registered and it overflows a
buffer inside SER somewhere that causes that packet that goes back to the
ATA to become corrupt, so the ATA thinks it failed and registers again.
I'm not entirely sure why the ATA is doing this (firmware 2.16.2) but a
possible fix would be to hack SER to remove all the previous contacts in
the db when it's seen again? I'll have to look into that.
- Mike
On Thu, 6 Nov 2003, Jiri Kuthan wrote:
The part which strikes me is the port number in
contact.
The 200 returns lot of such contacts with ascending port
number. A possible explanation is that the ATA mistakenly
registers all over again contacts which are differnt
each timer (different port number). They are handled
as distinct contact by SER and that's why so many appear
in 200.
Maybe it happens because ATA does not think it received
the reply. It is a bad practice that it solicits replies
at a different port number (1388) than from which it sends
(1387).
Try sending replies to origination port by calling force_rport
from your script. Or even better, make your ATA receive
at port number from where it sends. (I don't know how, though.)
-jiri
At 01:00 AM 11/6/2003, Mike wrote:
After playing around with the new firmware (and
new SER cvs snapshot
0.8.12dev-22-tcp_aliases) I'm seeing some very strange behavior from SER
(ngrep trace follows):
U 1.1.19.48:1387 -> 1.1.16.55:5060
REGISTER sip:sip.test.net SIP/2.0..Via: SIP/2.0/UDP 1.1.19.48:1388..From:
<sip:6526@sip.test.net;user=phone>;tag=50886574..T
o: <sip:6526@sip.test.net;user=phone>..Call-ID: 4136319346@10.118.145.13..CSeq:
160 REGISTER..Contact: <sip:6526@1.1.19.48:
1388;user=phone;transport=udp>;expires=1800..User-Agent: Cisco ATA 186 v2.16.2
ata18x (030909a)..Content-Length: 0....
#
U 1.1.16.55:5060 -> 1.1.19.48:1388 25017@0:1480
...l....SIP/2.0 200 OK..Via: SIP/2.0/UDP 1.1.19.48:1388..From:
<sip:6526@sip.test.net;user=phone>;tag=50886574..To: <sip:65
26@sip.test.net;user=phone>;tag=0596aef19d8edd571cbf9827f60616bb.97c5..Call-ID:
4136319346@10.118.145.13..CSeq: 160 REGISTER..Co
ntact:
<sip:6526@1.1.19.48:1376;user=phone;transport=udp>;q=0.00;expires=30..Contact:
<sip:6526@1.1.19.48:1377;user=p
hone;transport=udp>;q=0.00;expires=56..Contact:
<sip:6526@1.1.19.48:1378;user=phone;transport=udp>;q=0.00;expires=517..Con
tact:
<sip:6526@1.1.19.48:1379;user=phone;transport=udp>;q=0.00;expires=527..Contact:
<sip:6526@1.1.19.48:1380;user=p
hone;transport=udp>;q=0.00;expires=652..Contact:
<sip:6526@1.1.19.48:1381;user=phone;transport=udp>;q=0.00;expires=780..Co
ntact:
<sip:6526@1.1.19.48:1382;user=phone;transport=udp>;q=0.00;expires=911..Contact:
<sip:6526@1.1.19.48:1383;user=
phone;transport=udp>;q=0.00;expires=1040..Contact:
<sip:6526@1.1.19.48:1385;user=phone;transport=udp>;q=0.00;expires=1303.
.Contact:
<sip:6526@1.1.19.48:1386;user=phone;transport=udp>;q=0.00;expires=1532..Contact:
<sip:6526@1.1.19.48:1387;u
ser=phone;transport=udp>;q=0.00;expires=1576..Contact:
<sip:6526@1.1.19.48:1388;user=phone;transport=udp>;q=0.00;expires=1
800..Server: Sip EXpress router (0.8.12dev-22-tcp_aliases (i386/linux))..Content-Length:
0..Warning: 392 sip.test.net:5060 "Nois
y feedback tells: pid=11260 req_src_ip=1.1.19.48 req_src_port=1387 in_uri=sip
This is repeated over and over and over again. This seems very bizzare to
me. ATAs with earlier firmware don't trigger this behavior. The only
thing that I can see different in the register request is the addition of
the tag in the From: line:
From: <sip:6526@sip.test.net;user=phone>;tag=50886574
whereas the old ATA registers with:
From: <sip:6526@sip.test.net;user=phone>
Any clues?? Thanks!!
- Mike
_______________________________________________
Serusers mailing list
serusers(a)lists.iptel.org
http://lists.iptel.org/mailman/listinfo/serusers
--
Jiri Kuthan http://iptel.org/~jiri/
11:08 a.m.
At 05:26 AM 11/6/2003, Mike wrote:
[...]
I'm not entirely sure why the ATA is doing this
(firmware 2.16.2) but a
possible fix would be to hack SER to remove all the previous contacts in
the db when it's seen again? I'll have to look into that.
Have you tried the two tricks I mentioned? force_rport and making the ATA
symmetric somehow?
-jiri
12:30 p.m.
On Nov 05, 2003 at 19:00, Mike <voipguy(a)spam.turbolink.net> wrote:
After playing around with the new firmware (and new SER cvs snapshot
0.8.12dev-22-tcp_aliases) I'm seeing some very strange behavior from SER
(ngrep trace follows):
U 1.1.19.48:1387 -> 1.1.16.55:5060
REGISTER sip:sip.test.net SIP/2.0..Via: SIP/2.0/UDP 1.1.19.48:1388..From:
<sip:6526@sip.test.net;user=phone>;tag=50886574..T
o: <sip:6526@sip.test.net;user=phone>..Call-ID: 4136319346@10.118.145.13..CSeq:
160 REGISTER..Contact: <sip:6526@1.1.19.48:
1388;user=phone;transport=udp>;expires=1800..User-Agent: Cisco ATA 186 v2.16.2
ata18x (030909a)..Content-Length: 0....
#
U 1.1.16.55:5060 -> 1.1.19.48:1388 25017@0:1480
...l....SIP/2.0 200 OK..Via: SIP/2.0/UDP 1.1.19.48:1388..From: <sip:6526@s
^^^^^^^^
Is there really garbage before SIP or is this a ngrep artifact?
(a tcpdump -s 1514 -w /tmp/dump would help)
Apart from this the reply seems ok. It is fragmented and the whole
message is huge (25017@0:1480).
Maybe the ATA doesn't deal well with packets this size, or a firewall
drops the fragments.
Andrei
12:43 p.m.
Andrei Pelinescu-Onciul writes:
i have also seen ngrep missing parts of working messages, so i suspect
there is a bug in ngrep.
-- juha
U
1.1.16.55:5060 -> 1.1.19.48:1388 25017@0:1480
...l....SIP/2.0 200 OK..Via: SIP/2.0/UDP 1.1.19.48:1388..From: <sip:6526@s
^^^^^^^^
Is there really garbage before SIP or is this a ngrep artifact?
12:50 p.m.
At 11:43 AM 11/6/2003, Juha Heinanen wrote:
Andrei Pelinescu-Onciul writes:
i have also seen ngrep missing parts of working messages, so i suspect
there is a bug in ngrep.
so do I. ngrep is guilty. -jiri
U
1.1.16.55:5060 -> 1.1.19.48:1388 25017@0:1480
...l....SIP/2.0 200 OK..Via: SIP/2.0/UDP 1.1.19.48:1388..From: <sip:6526@s
^^^^^^^^
Is there really garbage before SIP or is this a ngrep artifact?
7691
days inactive
7691
days old
6 comments
4 participants
participants (4)
-
Andrei Pelinescu-Onciul -
Jiri Kuthan -
Juha Heinanen -
Mike