Search
GXW4104 VoIP to PSTN probs after firmware update
vassilis
I have downloaded and installed firmware version 1.0.1.10.
Now the status page reports:
Software Version: Program-- 1.0.1.10 Loader-- 1.1.3.4 Boot-- 1.1.3.2
I have connected ports 1 and 2 to my Samsung SKP-816EX PABX in order to
run some configuration tests.
Unfortunately, after the upgrade the follwoing problem came up:
I am using the rule in extensions.conf:
; internal phones via PBX **********************
exten => _10XX,1,Dial(SIP/$[${EXTEN}-980]@gs4fxo)
so that, say, dialing ext. 1010, the GXW4104 will dial 30 which
corresponds to the Samsung ext. 10.
With the previous release (1.0.0.55) this worked just fine, but with
the new firmware, I have the following behavior:
1) Asterisk bridges the call:
-- Executing [1010@main:1] Dial("SIP/VP-80ef3000", "SIP/30@gs4fxo") in new stack
-- Called 30@gs4fxo
-- SIP/gs4fxo-888d6000 is ringing
-- SIP/gs4fxo-888d6000 answered SIP/VP-80ef3000
-- Packet2Packet bridging SIP/VP-80ef3000 and SIP/gs4fxo-888d6000
2) The phone connected to ext. 10 on the Samsung rings (and if
I pick it up immediately, I can briefly talk)
3) The GXW4104 hangs up the call:
18:04:34.619984 gs4fxo.sip > astero.sip: [udp sum ok] udp 475 (DF) (ttl 255, id 1014, len 503)
0000: 4500 01f7 03f6 4000 ff11 e067 c0a8 0a3d E..÷.ö@.ÿ.àgÀ¨.=
0010: c0a8 0a0a 13c4 13c4 01e3 dc24 4259 4520 À¨...Ä.Ä.ãÜ$BYE
0020: 7369 703a 3330 4031 3932 2e31 3638 2e31 sip:30@192.168.1
0030: 302e 3130 3b75 7365 723d 7068 6f6e 6520 0.10;user=phone
0040: 5349 502f 322e 300d 0a56 6961 3a20 5349 SIP/2.0..Via: SI
0050: 502f 322e 302f 5544 5020 3139 322e 3136 P/2.0/UDP 192.16
0060: 382e 3130 2e36 313a 3530 3630 3b62 7261 8.10.61:5060;bra
0070: 6e63 683d 7a39 6847 3462 4b35 6531 3439 nch=z9hG4bK5e149
0080: 3131 3736 6236 3234 3965 350d 0a46 726f 1176b6249e5..Fro
0090: 6d3a 2022 5650 2d4f 6666 6963 6522 203c m: "VP-Office" <
00a0: 7369 703a 4f75 7473 6964 654c 696e 6540 sip:OutsideLine@
00b0: 3139 322e 3136 382e 3130 2e31 303e 3b74 192.168.10.10>;t
00c0: 6167 3d61 7330 3037 3637 3065 340d 0a54 ag=as007670e4..T
00d0: 6f3a 2022 5650 2d4f 6666 6963 6522 203c o: "VP-Office" <
00e0: 7369 703a 4f75 7473 6964 654c 696e 6540 sip:OutsideLine@
00f0: 3139 322e 3136 382e 3130 2e31 303e 3b74 192.168.10.10>;t
0100: 6167 3d61 7330 3037 3637 3065 340d 0a43 ag=as007670e4..C
0110: 616c 6c2d 4944 3a20 3838 6530 3738 6631 all-ID: 88e078f1
0120: 3966 3136 3730 3231 4031 3932 2e31 3638 9f167021@192.168
0130: 2e31 302e 3631 0d0a 4353 6571 3a20 3338 .10.61..CSeq: 38
0140: 3036 2042 5945 0d0a 5573 6572 2d41 6765 06 BYE..User-Age
0150: 6e74 3a20 4772 616e 6473 7472 6561 6d20 nt: Grandstream
0160: 4758 5734 3130 3420 2848 5720 312e 302c GXW4104 (HW 1.0,
0170: 2043 683a 3229 2031 2e30 2e31 2e31 300d Ch:2) 1.0.1.10.
0180: 0a4d 6178 2d46 6f72 7761 7264 733a 2037 .Max-Forwards: 7
0190: 300d 0a41 6c6c 6f77 3a20 494e 5649 5445 0..Allow: INVITE
01a0: 2c41 434b 2c43 414e 4345 4c2c 4259 452c ,ACK,CANCEL,BYE,
01b0: 4e4f 5449 4659 2c52 4546 4552 2c4f 5054 NOTIFY,REFER,OPT
01c0: 494f 4e53 2c49 4e46 4f2c 5355 4253 4352 IONS,INFO,SUBSCR
01d0: 4942 452c 5550 4441 5445 2c50 5241 434b IBE,UPDATE,PRACK
01e0: 0d0a 436f 6e74 656e 742d 4c65 6e67 7468 ..Content-Length
01f0: 3a20 300d 0a0d 0a : 0....
4) Asterisk notices that the GXW4104 is no longer listening on the
existing port and reports an error
[Oct 27 18:04:34] NOTICE[26681]: chan_sip.c:13879 handle_request_invite: Call from 'gs4fxo' to extension '30' rejected because extension not found.
5) When the caller hangs up, Asterisk reports an additional error:
[Oct 27 18:04:38] WARNING[26681]: chan_sip.c:12735 handle_response: Remote host can't match request BYE to call '59b4fc471b018ad97c9745670f4c7259@192.168.10
.10'. Giving up.
--------------------------------------------------------
Additional Info:
a) The GXW4104 is configured without SIP accounts, and the sip.conf entry is:
[gs4fxo]
type=friend
context=incoming
host=gs4fxo.prevelakis.com
insecure=port
canreinvite=yes ; do not force call bridging via asterisk
fromuser=OutsideLine
b) Syslog logs sent by the GXW4104
Oct 27 18:04:29 gs4fxo GS_LOG: [00:0B:82:0D:FC:4B][000][FF50][1.0.1.10] 728 sip.c Sess: 0 Send SIP message: 100 To 192.168.10.10:5060
Oct 27 18:04:29 gs4fxo GS_LOG: [00:0B:82:0D:FC:4B][000][FF50][1.0.1.10] 680 sip_handle_invite.c Sess: 2 INVITE From="VP-Office"
Oops previous post was truncated...Notice in the syslog records below, that the GXW4104 reports the"Deletion of invalid timer: [2] 0 cm_utility.c:639"I am not sure whether this is significant, but it sure looks suspicious.Thanks**vp
--------------------------------------------------------
Additional Info:
a) The GXW4104 is configured without SIP accounts, and the sip.conf entry is:
[gs4fxo]
type=friend
context=incoming
host=gs4fxo.prevelakis.com
insecure=port
canreinvite=yes ; do not force call bridging via asterisk
fromuser=OutsideLine
b) Syslog logs sent by the GXW4104
Oct 27 18:04:29 gs4fxo GS_LOG: [00:0B:82:0D:FC:4B][000][FF50][1.0.1.10]
728 sip.c Sess: 0 Send SIP message: 100 To 192.168.10.10:5060
Oct 27 18:04:29 gs4fxo GS_LOG: [00:0B:82:0D:FC:4B][000][FF50][1.0.1.10]
680 sip_handle_invite.c Sess: 2 INVITE From="VP-Office"
<sip:OutsideLine@192.168.10.10>;tag=as007670e4 To=<sip:30@gs4fxo.prevelakis.com>
Oct 27 18:04:29 gs4fxo GS_LOG: [00:0B:82:0D:FC:4B][000][FF50][1.0.1.10]
761 log user data from file: sip_handle_invite.c Port:1 Sess:2;1
1 0;0 1 400 400,11 11,500 0 0,500 0 0,2 0 ch1-4:N; 100;0 1 9600
1;1 0 1 1;7 5062 0 0;4 1 2 99
Oct 27 18:04:30 gs4fxo GS_LOG: [00:0B:82:0D:FC:4B][000][FF50][1.0.1.10]
728 sip.c Sess: 2 Send SIP message: 180 To 192.168.10.10:5060
Oct 27 18:04:30 gs4fxo GS_LOG: [00:0B:82:0D:FC:4B][000][FF50][1.0.1.10]
sdp.c Acc:0 RTP payload type: 0
Oct 27 18:04:30 gs4fxo GS_LOG: [00:0B:82:0D:FC:4B][000][FF50][1.0.1.10]
728 sip.c Sess: 2 Send SIP message: 200 To 192.168.10.10:5060
Oct 27 18:04:30 gs4fxo GS_LOG: [00:0B:82:0D:FC:4B][000][FF50][1.0.1.10]
cm_api.c 246 Start fax_detect on Port:1 sess: 2
Oct 27 18:04:34 gs4fxo GS_LOG: [00:0B:82:0D:FC:4B][000][FF50][1.0.1.10]
728 sip.c Sess: 2 Send SIP message: 2 To 192.168.10.10:5060
Oct 27 18:04:34 gs4fxo GS_LOG: [00:0B:82:0D:FC:4B][000][FF50][1.0.1.10]
728 sip.c Sess: 2 Send SIP message: 3 To 192.168.10.10:5060
Oct 27 18:04:34 gs4fxo GS_LOG: [00:0B:82:0D:FC:4B][000][FF50][1.0.1.10]
616 cm_utility.c Port:1 Sess:2 app_st: 4 drv_cs: 8 from#: 669
Oct 27 18:04:34 gs4fxo GS_LOG: [00:0B:82:0D:FC:4B][707][FF50][1.0.1.10]
Deletion of invalid timer: [2] 0 cm_utility.c:639
Oct 27 18:04:34 gs4fxo GS_LOG: [00:0B:82:0D:FC:4B][000][FF50][1.0.1.10]
728 sip.c Sess: 2 Send SIP message: 4 To 192.168.10.10:5060
Oct 27 18:04:36 gs4fxo GS_LOG: [00:0B:82:0D:FC:4B][000][FF50][1.0.1.10]
600 cm_utility.c Port:1 Sess:2 app_st: 4 drv_cs: 0
Oct 27 18:04:38 gs4fxo GS_LOG: [00:0B:82:0D:FC:4B][000][FF50][1.0.1.10]
728 sip.c Sess: 0 Send SIP message: 481 To 192.168.10.10:5060
Update:
The problem with the disconnect is an extra INVITE message sent by the GXW4104 after asterisk has started relaying voice traffic between the GXW4104 and the VoIP phone. Asterisk responds with a "Not Found" message and then the GXW4104 issues a "BYE" message and turns off the port.
Going the other way, i.e. calling the VoIP phone from the GXW4104 works fine (the extra INVITE message is not generated).
Now the really confusing bit is that in the original case of the VoIP phone trying to access the PABX via the GXW4104, if I send a one digit number (e.g. a 9 to get an outside line), this works!
If I ask the GXW4104 to dial a longer number (either directly or via the dial plan), then the additional INVITE message is sent and the connection is dropped.
Note also that all this is without SIP accounts on the GXW4104. If I enable SIP accounts things become even more confusing. In this case the INVITE message apparently uses the id of the NEXT port (ie. if we use port 1 with id 701, the second INVITE uses 702 as the id).
The more I look at it, the more confused I get.
**vp
Some good news and some bad
In my first posting I mentioned that Asterisk gave the error:
[Oct 27 18:04:34] NOTICE[26681]: chan_sip.c:13879
handle_request_invite: Call from 'gs4fxo' to extension '30'
rejected because extension not found.
after receiving the second INVITE message.
To see if I could fix this, I created a bogus extension 30
exten => 30,1,hangup()
in the same context as the GXW4104 and suddenly everything was working again.
Unfortunately, I do not have traces from the previous release to compare
with the current one, to see what is the root problem (the fake extension
being a kludge).
When I thought that everything was now OK, I realized that now the
behavior of the the system was erratic, in the sense that some calls
were dropped. For example, I'd call one of the ports of the GXW4104
and the call would go through, but other times the call would be
dropped after two rings. The GXW4104 hangs up the port, issues
a BYE to asterisk and the SIP phone is left with silence.
This kind of behavior is really disturbing and I would like to
investigate how I can go back to the earlier release of the
software. At least in that case the system was behaving in a
consistent manner.
Thanks
**vp
BTW I thought this forum was supposed to help users resolve problems, but it looks like I am simply documenting my efforts at helping myself.
Further to the workaround described above, I see that on the asterisk side the 2nd INVITE message creates a dummy connection:
Peer User/ANR Call ID Seq (Tx/Rx) Format Hold Last Message
192.168.10.61 21 77270452dbd 00101/14975 0x8 (alaw) No Rx: ACK
192.168.10.61 21 15215668648 00102/00000 0x8 (alaw) No Tx: ACK
192.168.10.63 VP 3e7c82c1606 00101/00802 0x8 (alaw) No Rx: ACK
If on the other hand the 2nd INVITE is *NOT* sent, then I have the expected two calls:
192.168.10.61 21 2e2fa54650f 00102/00000 0x8 (alaw) No Tx: ACK
192.168.10.63 VP 37e53a3d2a5 00101/00802 0x8 (alaw) No Rx: ACK
You may well think that as long as this works, then all is fine, but my problem now is that I am forced to have bogus entries in the asterisk extensions file, plus the incoming voice channel (PSTN side) is apparently sent to the dummy connection. So no audio to the SIP phone.
Great!
**vp
