[Home]

Summary:ASTERISK-07247: NOTIFY sent to the wrong IP address/port
Reporter:fjt99 (fjt99)Labels:
Date Opened:2006-06-29 00:33:00Date Closed:2006-10-03 16:20:06
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/Subscriptions
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) Debugging_BLF.txt
Description:I have a single asterisk (1.2.9.1) box that has 2 separate companies hosted on it. As both companies can have the same extension numbers (i.e. 1003) things are very explicit in the dial plan. Some phones must register for extensions in both companies and also subscribe for BLF. I am using Grandstream GXP-2000 phones for these people and sometimes asterisk will send the hint info to the wrong port. Once it happens, only way to fix is restart asterisk and reboot phones to cause them to re-register. Will work for a while (1 hour to a day or 2) then the problem will appear again.

For example, account 1 on the phone registers for company ABC, ext. 1004 and uses port 5060. Account 4 on the phone registers for company XYZC, ext. 1004 and uses port 5066. If BLF light 1 is subscribed to company ABC ext. 1003 and BLF light 2 is subscribed to company XYZC ext. 1003, a call comes in to ABC ext 1003 but asterisk send the hint info to port 5066 and not port 5060. See SIP info in additional information.


****** ADDITIONAL INFORMATION ******

Here is the peers and hints, all looks correct.

pbx*CLI> sip show peers
Name/username              Host            Dyn Nat ACL Port     Status    
xyzc-1005/xyzc-1005        10.0.30.175      D   N   A  5066     Unmonitored
xyzc-1004/xyzc-1004        10.0.30.183      D   N   A  5066     Unmonitored
xyzc-1003/xyzc-1003        10.0.30.176      D   N   A  5066     Unmonitored
xyzc-1001/xyzc-1001        (Unspecified)    D   N   A  0        UNKNOWN  
abc-1006/abc-1006          (Unspecified)    D   N   A  0        Unmonitored
abc-1005/abc-1005          10.0.30.175      D   N   A  5060     Unmonitored
abc-1004/abc-1004          10.0.30.183      D   N   A  5060     Unmonitored
abc-1003/abc-1003          10.0.30.176      D   N   A  5060     Unmonitored
8 sip peers [7 online , 1 offline]


pbx*CLI> sip show subscriptions
Peer             User        Call ID      Extension        Last state     Type          
10.0.30.183      abc-1004    a599957fa94  abchint1003      Idle           dialog-info+xml
10.0.30.183      xyzc-1004   8c93004b682  xyzchint1003     Idle           dialog-info+xml
10.0.30.175      xyzc-1005   fa4b6209e62  xyzchint1004     Idle           dialog-info+xml
10.0.30.175      xyzc-1005   29cbcd55439  xyzchint1003     Idle           dialog-info+xml
10.0.30.176      xyzc-1003   894be009052  xyzchint1005     Idle           dialog-info+xml
10.0.30.176      xyzc-1003   84c809555e8  xyzchint1004     Idle           dialog-info+xml
10.0.30.175      abc-1005    ba2a4d7ddd4  abchint1004      Idle           dialog-info+xml
10.0.30.175      abc-1005    7499347fa8e  abchint1003      Idle           dialog-info+xml
10.0.30.176      abc-1003    9d2ac08db1b  abchint1005      Idle           dialog-info+xml
10.0.30.176      abc-1003    f799087f4c4  abchint1004      Idle           dialog-info+xml
10 active SIP subscriptions


Now a call comes in on Zap/1-1 and goes to abc-1003. It should send hints to 10.0.30.175:5060 and 10.0.30.183:5060

The hint info to 10.0.30.175:5060 looks fine:

Reliably Transmitting (NAT) to 10.0.30.175:5060:
NOTIFY sip:abc-1005@10.0.30.175:5060 SIP/2.0 Via: SIP/2.0/UDP 10.0.30.10:5060;branch=z9hG4bK088b2c3f;rport From: <sip:abchint1003@10.0.30.10;user=phone>;tag=as7b9be2c4 To: "Accounting" <sip:abc-1005@10.0.30.10>;tag=e9555c278516709f Contact: <sip:abchint1003@10.0.30.10> Call-ID: 7499347fa8ec1241@10.0.30.175 CSeq: 408 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 236
<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="306" state="full" entity="sip:abchint1003@10.0.30.10">
<dialog id="abchint1003" direction="recipient">
<state>early</state>
</dialog>
</dialog-info>


But the hint to 10.0.30.183 goes to port 5066 (xyzc-1004), not 5060 (abc-1004) like it should:

Reliably Transmitting (NAT) to 10.0.30.183:5066:
NOTIFY sip:xyzc-1004@10.0.30.183:5066 SIP/2.0 Via: SIP/2.0/UDP 10.0.30.10:5060;branch=z9hG4bK4cea4143;rport From: <sip:abchint1003@10.0.30.10;user=phone>;tag=as71d9fcc2 To: "Frank Thomson" <sip:abc-1004@10.0.30.10>;tag=22ec48bfb1afac9f Contact: <sip:abchint1003@10.0.30.10> Call-ID: a599957fa94923ef@10.0.30.183 CSeq: 123 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 235  
<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="21" state="full" entity="sip:abchint1003@10.0.30.10">
<dialog id="abchint1003" direction="recipient">
<state>early</state>
</dialog>
</dialog-info>

Comments:By: Olle Johansson (oej) 2006-06-29 02:25:36

Test using the subscribecontext configuration setting to separate the companies. Read the sip.conf.sample file in the distribution!
By: Olle Johansson (oej) 2006-06-29 02:28:09

A terminology note, since you confused me: Subscriptions and hints is not the same. hints is a dialplan item shown with "show hints" in the CLI. Subscriptions subscribe to an extension status and sends notifications. Thanks.
By: fjt99 (fjt99) 2006-06-29 11:11:39

Already using subscribecontext in sip.conf. Each has a separate context to subscribe to. Here is an example sip.conf entry:

[abc-1004]
type=friend
regexten=1004
callerid="Frank Thomson" <1004>
username=abc-1004
md5secret=XXXXXXXXXXXXXXXXXXXXXXX
host=dynamic
mailbox=1004@abc-vm
canreinvite=no
context=abc-internal
subscribecontext=abc-blf
disallow=all
allow=ulaw
deny=0.0.0.0/0.0.0.0
permit=10.0.0.0/255.255.0.0
accountcode=ABCCorp

in the extensions file I have:
[abc-blf]
exten => abchint1003,hint,SIP/abc-1003
exten => abchint1004,hint,SIP/abc-1004
exten => abchint1005,hint,SIP/abc-1005

Similar thing is done for xyzc.

Sorry about confusion on hint/subscription comments. I used hint incorrectly, was tired as I wrote it up. Have been trying to figure out what was going on since everything else is working so well: extensions, voicemail, IVR, etc. are all separate, working properly, never had any issue (been in production for 8 months). Only BLF seems to have an issue and only on those phones with multiple registrations to the same server.
By: Olle Johansson (oej) 2006-06-30 03:01:53

I need to see a debug of the actual subscriptions coming in *and* the notifications going out. Thanks.
By: fjt99 (fjt99) 2006-06-30 17:56:00

Uploaded text file is a register/subscription (rebooted the GXP-2000) from sip debug and a notify that goes to the wrong port. This is from the live system so some names are different but config files are identical. A little extra info that may help:

10.0.30.10: Asterisk server

10.0.30.183: My phone I've been testing with. Registers as oct-1004 on port 5060 and spin-1004 on port 5066. Subscribes to oct-1003,oct-1005,spin-1003,spin-1005

10.0.30.176: A phone that registers as oct-1003 (5060) and spin-1003 (5066). Also a GXP-2000 and subscribes to oct-1004, oct-1005, spin-1004, spin-1005

Top of file to the "sip show subscriptions" is everything from the time I reset the GXP-2000 to the point it seemed to be finished.

Time passed and all worked well. Then I noticed a call come into oct-1003 and the BLF on my phone did not light (did work earlier). That trace is at the end of the file.
By: fjt99 (fjt99) 2006-07-08 19:24:44

Any more on this? My users are bugging me about getting it working. I have tried to look at the code myself but I am not well enough versed in the internals of asterisk.
By: none (algorithmn) 2006-08-07 14:52:13

i honestly think its a grandstream issue.  note the differences on the port numbers for each seperate account on your grandstream hardphone.  this may be your problem.  i've noticed grandstream phones 'blend' different settings between accounts....

a quick solution... use 1 account per hardware phone...

hope this helps..
By: fjt99 (fjt99) 2006-08-08 18:20:19

Originally thought it was a Grandstream issue but looking at the SIP messages I can see that at times Asterisk is sending to a port other than the one used in the subscribe request for a particular subscription.

Since we have a few phones that must be subscribed to two different accounts, not realistic to use one account per hardphone. So we are simply hoping that either the asterisk developers get a chance to look into it or I am able to understand the code (ok, slim chance on the second but I do try to look at it) and fix it.
By: Serge Vecher (serge-v) 2006-08-09 08:56:53

fjt99: the sip log you've atttached does not contain any of the [debug] messages. Please follow these instructions to produce a SIP Debug log oej is looking for.

1) Prepare test environment (reduce the ammount of unrelated traffic on the server);
2) Make sure your logger.conf has the following line:
  console => notice,warning,error,debug
3) restart Asterik.
4) Enable SIP transaction logging with the following CLI commands:
set debug 4
set verbose 4
sip debug
5) Save complete console log to file and _attach_ said file to the bug.
By: Serge Vecher (serge-v) 2006-08-09 08:58:55

also, please make sure you update to 1.2.10 too.
By: fjt99 (fjt99) 2006-08-12 13:58:33

Have updated to 1.2.10. Will watch and see what happens.

Sorry about not getting the debug log correct, will create new one but that may take a week or two. We are moving and getting the time to experiment on the system is a little difficult.
By: fjt99 (fjt99) 2006-08-16 14:10:22

Just a quick FYI, have seen same issue in 1.2.10. Will try to make debug log ASAP but due to our move it may still be a week or two...
By: Serge Vecher (serge-v) 2006-09-06 11:11:39

ok, it's been three weeks now.
By: fjt99 (fjt99) 2006-09-11 16:50:43

Sorry for delay, but moves never go as planned...
Tried to make the debug file this weekend and the error did not appear. Finally had to stop it due to the file getting so large (ran it from Saturday morning through about noon today). Will try again in a few days and hope error shows up while the debug is going.
By: Serge Vecher (serge-v) 2006-09-13 10:07:28

alright, do test with 1.2.12.1 release too.
By: Serge Vecher (serge-v) 2006-10-03 16:20:05

feel free to reopen when/if you reproduce and able to get the debugging information. Do also test the 1.4-beta.