Voxalot / SIP Broker Support Forums

Voxalot / SIP Broker Support Forums (https://forum.sipbroker.com/index.php)
-   Voxalot Support (https://forum.sipbroker.com/forumdisplay.php?f=4)
-   -   No Reponse to VM SUBSCRIBE message? (https://forum.sipbroker.com/showthread.php?t=133)

BJReplay 05-03-2006 02:09 AM
No Reponse to VM SUBSCRIBE message?
 
OK, quick background...

VM is working for me - calls get fowarded to VM on no answer by the SPA, and I get VMWI and stutter tone MWI when there's a VM. All Good. :)

However, I noticed a fair amount of traffic, and a significant excess of outgoing SIP messages to incoming SIP messages, so I thought i'd throw a syslogger at the problem.

What appears to be happening is that the SPA is trying to subscribe to VM, but getting no response to the subscribes. It sends 15 subscribes (or thereabouts) over 60 seconds, then waits 30 seconds before trying again. I imagine the voxalot servers don't appreciate this.

However, usually in the middle of all this, voxalot nicely sends a notify - which the SPA acks.

Have I stuffed up my SPA settings to cause this, or should voxalat be acking the subscribes? Is the problem that the call id in my sub requests is an internal IP addy (192.168.1.3) or is that a red herring?

PM for account details if you want to debug - I've removed them from the syslog data.

Code:
[0:5060]->71.13.117.133:5060
SUBSCRIBE sip:111111@voxalot.com SIP/2.0
Via: SIP/2.0/UDP my.external.ip.addy:5060;branch=z9hG4bK-d786e18d
From: MyUserName <sip:111111@voxalot.com>;tag=c6a3dd958a4ab3eb
To: MyUserName <sip:111111@voxalot.com>
Call-ID: 943165d-f78391c3@192.168.1.3
CSeq: 56806 SUBSCRIBE
Max-Forwards: 70
Authorization: Digest username="111111",realm="voxalot.com",nonce="
aHexEncodedNonce",uri="sip:111111@voxalot.com",algorithm=MD5,response
="aHexEncodedResponse"
Contact: MyUserName <sip:111111@my.external.ip.addy:5060>
Expires: 600
Event: message-summary
User-Agent: Linksys/SPA3000-3.1.10(GWd)
Content-Length: 0
.... Repeated 5 times over 20 seconds ....

Then, in the middle I get:

Code:
[0:5060]<<71.13.117.133:5060
NOTIFY sip:111111@my.external.ip.addy:5060 SIP/2.0
Max-Forwards: 10
Record-Route: <sip:71.13.117.133;lr=on>
Via: SIP/2.0/UDP 71.13.117.133;branch=z9hG4bKf9a4.c282f903.0
Via: SIP/2.0/UDP 71.13.117.133:44796;branch=z9hG4bK.51e9aaca;rport=44796;alias
Via: SIP/2.0/UDP 71.13.117.133:5060
From: <sip:vmserver@voxalot.com>
To: <sip:111111@voxalot.com>
Contact: <sip:111111@71.13.117.133>
Call-ID: aHexEncodedCallID@71.13.117.133
CSeq: 1 NOTIFY
User-Agent: VoiceMail
Event: message-summary
Content-Type: application/simple-message-summary
Content-Length: 81
P-hint: usrloc applied

Messages-Waiting: no
Message-Account: sip:111111@voxalot.com
Voice-Message: 0/0
To which the SPA responds....

Code:
[0:5060]->71.13.117.133:5060
SIP/2.0 200 OK
To: <sip:111111@voxalot.com>;tag=d64ff3f3f69f1819i0
From: <sip:vmserver@voxalot.com>
Call-ID: aHexEncodedCallID@71.13.117.133
CSeq: 1 NOTIFY
Via: SIP/2.0/UDP 71.13.117.133;branch=z9hG4bKf9a4.c282f903.0
Via: SIP/2.0/UDP 71.13.117.133:44796;branch=z9hG4bK.51e9aaca;rport=44796;alias
Via: SIP/2.0/UDP 71.13.117.133:5060
Record-Route: <sip:71.13.117.133;lr=on>
Server: Linksys/SPA3000-3.1.10(GWd)
Content-Length: 0
But it keeps trying to subscribe:

Code:
[0:5060]->71.13.117.133:5060
SUBSCRIBE sip:111111@voxalot.com SIP/2.0
Via: SIP/2.0/UDP my.external.ip.addy:5060;branch=z9hG4bK-d786e18d
From: MyUserName <sip:111111@voxalot.com>;tag=c6a3dd958a4ab3eb
To: MyUserName <sip:111111@voxalot.com>
Call-ID: 943165d-f78391c3@192.168.1.3
CSeq: 56806 SUBSCRIBE
Max-Forwards: 70
Authorization: Digest username="111111",realm="voxalot.com",nonce="
aHexEncodedNonce",uri="sip:111111@voxalot.com",algorithm=MD5,response
="aHexEncodedResponse"
Contact: MyUserName <sip:111111@my.external.ip.addy:5060>
Expires: 600
Event: message-summary
User-Agent: Linksys/SPA3000-3.1.10(GWd)
Content-Length: 0
.... Repeated 5 times over 20 seconds ....

Then issues this message

Code:
[0]SUBS:Failed(55). Retry in 30s

martin 05-03-2006 03:20 AM
Thanks for the detail. If I recall correctly (I will check a bit later as I am currently offsite) the responses to the SUBSCRIBES are not immediate.

Let us look at this tonight (after the server move) and I will respond with our findings.

BJReplay 05-03-2006 03:40 AM
Quote:
Originally Posted by martin
Thanks for the detail.
That's OK :)

I'll probably still be working till around 22:00EST so feel free to get in touch...

BJReplay 05-03-2006 04:39 AM
Just some more info
 
I syslogged the messages from a hard reboot, and noticed the following:

Code:
[0:5060]->71.13.117.133:5060
SUBSCRIBE sip:111111@voxalot.com SIP/2.0
Via: SIP/2.0/UDP my.external.ip.addy:5060;branch=z9hG4bK-81b87fd4
From: MyUserName <sip:111111@voxalot.com>;tag=69c2c5b71042d18a
To: MyUserName <sip:111111@voxalot.com>
Call-ID: 4e8276fb-78333116@192.168.1.3
CSeq: 29856 SUBSCRIBE
Max-Forwards: 70
Contact: MyUserName <sip:111111@my.external.ip.addy:5060>
Expires: 600
Event: message-summary
User-Agent: Linksys/SPA3000-3.1.10(GWd)
Content-Length: 0
Initial Subscribe Request, followed by a request to authenticate...

Code:
[0:5060]<<71.13.117.133:5060
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP my.external.ip.addy:5060;branch=z9hG4bK-81b87fd4
From: MyUserName <sip:111111@voxalot.com>;tag=69c2c5b71042d18a
To: MyUserName <sip:111111@voxalot.com>;tag=b27e1a1d33761e85846fc98f5f
3a7e58.c359
Call-ID: 4e8276fb-78333116@192.168.1.3
CSeq: 29856 SUBSCRIBE
WWW-Authenticate: Digest realm="voxalot.com", nonce="nonce"
Server: Sip EXpress router (0.9.4 (i386/linux))
Content-Length: 0
Warning: 392 71.13.117.133:5060 "Noisy feedback tells:  pid=26492 req_src_ip=my
.external.ip.addy req_src_port=5060 in_uri=sip:111111@voxalot.com out_uri=sip:111111@v
oxalot.com via_cnt==1"
Then followed by the repeated requests to subscribe (this time authenticated as per my previous log post).

Code:
[0:5060]->71.13.117.133:5060
SUBSCRIBE sip:111111@voxalot.com SIP/2.0
Via: SIP/2.0/UDP my.external.ip.addy:5060;branch=z9hG4bK-c02f4ba8
From: MyUserName <sip:111111@voxalot.com>;tag=69c2c5b71042d18a
To: MyUserName <sip:111111@voxalot.com>
Call-ID: 4e8276fb-78333116@192.168.1.3
CSeq: 29857 SUBSCRIBE
Max-Forwards: 70
Authorization: Digest username="111111",realm="voxalot.com",nonce="
nonce",uri="sip:111111@voxalot.com",algorithm=MD5,response
="f34d4c9831f14ae84746c5a3b04e6e07"
Contact: MyUserName <sip:111111@my.external.ip.addy:5060>
Expires: 600
Event: message-summary
User-Agent: Linksys/SPA3000-3.1.10(GWd)
Content-Length: 0
So I'm definitely getting an initial reply to the first attempt to subscribe (e.g. do it again, but authenticate), and it's definitely working, because I get the notifies, but no OK.

martin 05-03-2006 12:10 PM
Quote:
Originally Posted by BJReplay
So I'm definitely getting an initial reply to the first attempt to subscribe (e.g. do it again, but authenticate), and it's definitely working, because I get the notifies, but no OK.
Great spot :)

I just modified the SUBSCRIBE logic to return a 200 OK. The NOTIFY will still take up to 60secs to send after the 200 but let's see if the 200 at least keeps the ATA happy.

BJReplay 05-03-2006 12:40 PM
Magic:

[0]SubOK. NextSub in 599 (1)

My expires is currently set to 600. I'll bump it up to 43200 (12 hours).

martin 05-03-2006 12:46 PM
Great!

Thanks again for the diagnostics. Certainly makes it easier for us to turn around the fixes.


All times are GMT. The time now is 01:08 PM.

Powered by vBulletin® Version 3.7.2
Copyright ©2000 - 2024, Jelsoft Enterprises Ltd.