Home » Forums » Vendor Forums - Certified » Aastra endpoints

Device and User mode, BLF issue

gavroche95
Posts: 7
 Member Since:
2010-12-13
Submitted by gavroche95 on Tue, 03/08/2011 - 3:11am.

Hi all,

I have 100 (many more in a few weeks) of 6755i on which I need to use BLF/xfer feature.
I use Asterisk 1.6.2.12 in 'deviceanduser' mode and have plenty of people whom are login/out all the day.
For those reasons, users (and so me) need a really accurate BLF system.
I made a lot of tests with 2.6.0.66, 2.6.0.2010 and the fresh new 3.2.0.70 firmware, here are my results.

With 2.6.0.66 or 2.6.0.2010 firmware :
'sip show subscriptions' expiry reflects value given in 'user-custom.prf' if => 120
when an user logout, corresponding softkey become '?' after expiry period
'sip set debug peer XXXX' shows the phone never sends 'SUBSCRIBE' for un-logged (ie '?') users so when an user login, corresponding softkey '?' never changes until one of this occurs
  • complete logout and login of subscriber user
  • just a click on 'Save Settings' in 'Softkeys and XML' from the phone web page
    • With 3.2.0.70 firmware :
    'sip show subscriptions' expiry does not reflect value given in 'user-custom.prf', it's always near 3600 (3582,3591...)
    when an user logout, corresponding softkey become '?' after expiry period, about 1 hour
    'sip set debug peer XXXX' shows the phone sends 'SUBSCRIBE' for un-logged (ie '?') but did not reply to the '401 unauthorized' send by asterisk so when an user login, corresponding softkey '?' never changes except the same way as before

    I tried to bypass these behavour by forcing a reload of softkeys via the poll URI action and a personalized sync.php which clear all softkeys before re-creating. It works a couple of times and then with 2.6.0.210 new subscriptions never works until a complete reboot of the phone. With 3.2.0.70 same happens, but the phone restarts by itself, looks like some 'dogwatch' working great.

    Asked same question in Aastra Forum, get replied than a patch for 3.2.0 will correct BLF subscription period bug soon.

    Here is where I stand. Did I miss something on 'SUBSCRIBE' processing ? Am I alone to use BLF in 'deviceanduser' mode with that issue ? Could you please help me ?

    Regards,
    Bruno.

    ‹ Preventing "paging" screen to appear Aastra 55i with 2.3.0 XML Scripts -- dialing '0' for operator doesn't work ›


    SkykingOH
    Posts: 9682
     Member Since:
    2007-12-17
    I think this is a unique
    Tue, 03/08/2011 - 7:06am

    I think this is a unique situation.

    The iSymphony software has hooks into the XML scripts. This may do exactly what you want.

    Take a look at ww.i9technloogies.com

    I have no affiliation, just a user of the software.

    --

    Scott

    aka "Skyking"



    gavroche95
    Posts: 7
     Member Since:
    2010-12-13
    What do you mean by 'unique
    Tue, 03/08/2011 - 7:52am

    What do you mean by 'unique situation' ?

    I know ISymphony and we thought to deploy it for our attendants, but this it not a reliable solution for our hundreds users.
    BLF subscription is a feature able with Aastra phones and Asterisk, and it's more convenient for users to see a blinking led on phone than to have permantly an eye on ISymphony on their desktops.

    Regards,
    Bruno.



    gavroche95
    Posts: 7
     Member Since:
    2010-12-13
    3.2.0.1011 firmware testing
    Tue, 04/05/2011 - 1:43am

    Hi all,

    So here are the results of my week of testing this new patched firmware, eg 3.2.0.1011

    Sorry, this post will be long...

    Details of the testing environment:
    - astersik 1.6.2.12 in 'deviceanduser' mode : IP 10.22.1.201/23
    - 1 x 6730i firmware rev 2.6.0.2010 : DEVICE 1000, adhoc, no default user, IP 10.22.0.47/23
    - 1 x 6755i firmware rev 3.2.0.1011 : DEVICE 1024, adhoc, no default user, IP 10.22.0.44/23
    - USER 1731, no custom key, will use 6730i
    - USER 1614, softkey1 declared as blf/xfer to USER 1731, will use 6755i
    - BLF subscription period of 120
    - trace log obtained by 'sip set debug peer 1024'

    Case 1 : USER 1614 login after USER 1731

    <--- SIP read from UDP:10.22.0.44:5060 --->
SUBSCRIBE sip:1731@10.22.1.201:5060 SIP/2.0
Accept: application/dialog-info+xml
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bK6c7f5a08a1d8dde85
Max-Forwards: 70
From: <sip:1024@10.22.1.201:5060>;tag=58ebbed044
To: <sip:1731@10.22.1.201:5060>
Call-ID: af4200a394442cef
CSeq: 6398 SUBSCRIBE
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK, SUBSCRIBE, INFO
Allow-Events: aastra-xml, talk, hold, conference, LocalModeStatus
Contact: <sip:1024@10.22.0.44:5060;transport=udp>
Event: dialog
Expires: 129
Supported: path
User-Agent: Aastra 55i/3.2.0.1011
Content-Length: 0


<------------->
[Mar 31 17:17:48] VERBOSE[4394] chan_sip.c: --- (16 headers 0 lines) ---
[Mar 31 17:17:48] VERBOSE[4394] chan_sip.c: Creating new subscription
[Mar 31 17:17:48] VERBOSE[4394] chan_sip.c: Sending to 10.22.0.44 : 5060 (NAT)
[Mar 31 17:17:48] VERBOSE[4394] chan_sip.c: list_route: hop: <sip:1024@10.22.0.44:5060;transport=udp>
[Mar 31 17:17:48] VERBOSE[4394] chan_sip.c: Found peer '1024' for '1024' from 10.22.0.44:5060
[Mar 31 17:17:48] VERBOSE[4394] chan_sip.c: 
<--- Transmitting (NAT) to 10.22.0.44:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bK6c7f5a08a1d8dde85;received=10.22.0.44
From: <sip:1024@10.22.1.201:5060>;tag=58ebbed044
To: <sip:1731@10.22.1.201:5060>;tag=as1076a2af
Call-ID: af4200a394442cef
CSeq: 6398 SUBSCRIBE
Server: Asterisk PBX 1.6.2.12
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="63783f66"
Content-Length: 0


<------------>
[Mar 31 17:17:48] VERBOSE[4394] chan_sip.c: Scheduling destruction of SIP dialog 'af4200a394442cef' in 6400 ms (Method: SUBSCRIBE)
[Mar 31 17:17:48] VERBOSE[4394] chan_sip.c: 
<--- SIP read from UDP:10.22.0.44:5060 --->
SUBSCRIBE sip:1731@10.22.1.201:5060 SIP/2.0
Accept: application/dialog-info+xml
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bKec633cbb5adc9e94a
Max-Forwards: 70
From: <sip:1024@10.22.1.201:5060>;tag=58ebbed044
To: <sip:1731@10.22.1.201:5060>
Call-ID: af4200a394442cef
CSeq: 6399 SUBSCRIBE
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK, SUBSCRIBE, INFO
Allow-Events: aastra-xml, talk, hold, conference, LocalModeStatus
Authorization: Digest username="1024",realm="asterisk",nonce="63783f66",uri="sip:1731@10.22.1.201:5060",response="9066f197341d11faeb1a5c2abfc477da",algorithm=MD5
Contact: <sip:1024@10.22.0.44:5060;transport=udp>
Event: dialog
Expires: 129
Supported: path
User-Agent: Aastra 55i/3.2.0.1011
Content-Length: 0


<------------->
[Mar 31 17:17:48] VERBOSE[4394] chan_sip.c: --- (17 headers 0 lines) ---
[Mar 31 17:17:48] VERBOSE[4394] chan_sip.c: Creating new subscription
[Mar 31 17:17:48] VERBOSE[4394] chan_sip.c: Sending to 10.22.0.44 : 5060 (NAT)
[Mar 31 17:17:48] VERBOSE[4394] chan_sip.c: Found peer '1024' for '1024' from 10.22.0.44:5060
[Mar 31 17:17:48] VERBOSE[4394] chan_sip.c: Looking for 1731 in from-internal (domain 10.22.1.201)
[Mar 31 17:17:48] VERBOSE[4394] chan_sip.c: Scheduling destruction of SIP dialog 'af4200a394442cef' in 139000 ms (Method: SUBSCRIBE)
[Mar 31 17:17:48] VERBOSE[4394] chan_sip.c: 
<--- Transmitting (NAT) to 10.22.0.44:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bKec633cbb5adc9e94a;received=10.22.0.44
From: <sip:1024@10.22.1.201:5060>;tag=58ebbed044
To: <sip:1731@10.22.1.201:5060>;tag=as1076a2af
Call-ID: af4200a394442cef
CSeq: 6399 SUBSCRIBE
Server: Asterisk PBX 1.6.2.12
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Expires: 129
Contact: <sip:1731@10.22.1.201>;expires=129
Content-Length: 0


<------------>

    And after that, every 9 sec : 

    <--- SIP read from UDP:10.22.0.44:5060 --->
SUBSCRIBE sip:1731@10.22.1.201 SIP/2.0
Accept: application/dialog-info+xml
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bKb34c726acebfd282b
Max-Forwards: 70
From: <sip:1024@10.22.1.201:5060>;tag=58ebbed044
To: <sip:1731@10.22.1.201:5060>;tag=as1076a2af
Call-ID: af4200a394442cef
CSeq: 6400 SUBSCRIBE
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK, SUBSCRIBE, INFO
Allow-Events: aastra-xml, talk, hold, conference, LocalModeStatus
Authorization: Digest username="1024",realm="asterisk",nonce="63783f66",uri="sip:1731@10.22.1.201",response="25a13198f1ee05757e029ec8fd6c575a",algorithm=MD5
Contact: <sip:1024@10.22.0.44:5060;transport=udp>
Event: dialog
Expires: 129
Supported: path
User-Agent: Aastra 55i/3.2.0.1011
Content-Length: 0


<------------->
[Mar 31 17:17:57] VERBOSE[4394] chan_sip.c: --- (17 headers 0 lines) ---
[Mar 31 17:17:57] VERBOSE[4394] chan_sip.c: Found peer '1024' for '1024' from 10.22.0.44:5060
[Mar 31 17:17:57] NOTICE[4394] chan_sip.c: Correct auth, but based on stale nonce received from '<sip:1024@10.22.1.201:5060>;tag=58ebbed044'
[Mar 31 17:17:57] VERBOSE[4394] chan_sip.c: 
<--- Transmitting (NAT) to 10.22.0.44:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bKb34c726acebfd282b;received=10.22.0.44
From: <sip:1024@10.22.1.201:5060>;tag=58ebbed044
To: <sip:1731@10.22.1.201:5060>;tag=as1076a2af
Call-ID: af4200a394442cef
CSeq: 6400 SUBSCRIBE
Server: Asterisk PBX 1.6.2.12
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="2f8eecb9", stale=true
Content-Length: 0


<------------>
[Mar 31 17:17:57] VERBOSE[4394] chan_sip.c: Scheduling destruction of SIP dialog 'af4200a394442cef' in 6400 ms (Method: SUBSCRIBE)
[Mar 31 17:17:57] VERBOSE[4394] chan_sip.c: 
<--- SIP read from UDP:10.22.0.44:5060 --->
SUBSCRIBE sip:1731@10.22.1.201 SIP/2.0
Accept: application/dialog-info+xml
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bK8b0bf60720881eb81
Max-Forwards: 70
From: <sip:1024@10.22.1.201:5060>;tag=58ebbed044
To: <sip:1731@10.22.1.201:5060>;tag=as1076a2af
Call-ID: af4200a394442cef
CSeq: 6401 SUBSCRIBE
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK, SUBSCRIBE, INFO
Allow-Events: aastra-xml, talk, hold, conference, LocalModeStatus
Authorization: Digest username="1024",realm="asterisk",nonce="2f8eecb9",uri="sip:1731@10.22.1.201",response="497d3382b77a3cd1aa88149908ae5d0b",algorithm=MD5
Contact: <sip:1024@10.22.0.44:5060;transport=udp>
Event: dialog
Expires: 129
Supported: path
User-Agent: Aastra 55i/3.2.0.1011
Content-Length: 0


<------------->
[Mar 31 17:17:57] VERBOSE[4394] chan_sip.c: --- (17 headers 0 lines) ---
[Mar 31 17:17:57] VERBOSE[4394] chan_sip.c: Found peer '1024' for '1024' from 10.22.0.44:5060
[Mar 31 17:17:57] VERBOSE[4394] chan_sip.c: Looking for 1731 in from-internal (domain 10.22.1.201)
[Mar 31 17:17:57] VERBOSE[4394] chan_sip.c: Scheduling destruction of SIP dialog 'af4200a394442cef' in 139000 ms (Method: SUBSCRIBE)
[Mar 31 17:17:57] VERBOSE[4394] chan_sip.c: 
<--- Transmitting (NAT) to 10.22.0.44:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bK8b0bf60720881eb81;received=10.22.0.44
From: <sip:1024@10.22.1.201:5060>;tag=58ebbed044
To: <sip:1731@10.22.1.201:5060>;tag=as1076a2af
Call-ID: af4200a394442cef
CSeq: 6401 SUBSCRIBE
Server: Asterisk PBX 1.6.2.12
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Expires: 129
Contact: <sip:1731@10.22.1.201>;expires=129
Content-Length: 0


<------------>

    Questions :
    - why expiry is set to '129' instead of '120' ?
    - why resubscribe every 9 sec ?

    Case 2a : USER 1614 login before USER 1731

    <--- SIP read from UDP:10.22.0.44:5060 --->
SUBSCRIBE sip:1731@10.22.1.201:5060 SIP/2.0
Accept: application/dialog-info+xml
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bK5003ff38f8e1a20b4
Max-Forwards: 70
From: <sip:1024@10.22.1.201:5060>;tag=9788a809d0
To: <sip:1731@10.22.1.201:5060>
Call-ID: dd83810dbbdc72e4
CSeq: 27152 SUBSCRIBE
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK, SUBSCRIBE, INFO
Allow-Events: aastra-xml, talk, hold, conference, LocalModeStatus
Contact: <sip:1024@10.22.0.44:5060;transport=udp>
Event: dialog
Expires: 113
Supported: path
User-Agent: Aastra 55i/3.2.0.1011
Content-Length: 0


<------------->
[Mar 31 18:23:13] VERBOSE[4394] chan_sip.c: --- (16 headers 0 lines) ---
[Mar 31 18:23:13] VERBOSE[4394] chan_sip.c: Creating new subscription
[Mar 31 18:23:13] VERBOSE[4394] chan_sip.c: Sending to 10.22.0.44 : 5060 (NAT)
[Mar 31 18:23:13] VERBOSE[4394] chan_sip.c: list_route: hop: <sip:1024@10.22.0.44:5060;transport=udp>
[Mar 31 18:23:13] VERBOSE[4394] chan_sip.c: Found peer '1024' for '1024' from 10.22.0.44:5060
[Mar 31 18:23:13] VERBOSE[4394] chan_sip.c: 
<--- Transmitting (NAT) to 10.22.0.44:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bK5003ff38f8e1a20b4;received=10.22.0.44
From: <sip:1024@10.22.1.201:5060>;tag=9788a809d0
To: <sip:1731@10.22.1.201:5060>;tag=as474855fa
Call-ID: dd83810dbbdc72e4
CSeq: 27152 SUBSCRIBE
Server: Asterisk PBX 1.6.2.12
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="4cca66a8"
Content-Length: 0


<------------>
[Mar 31 18:23:13] VERBOSE[4394] chan_sip.c: Scheduling destruction of SIP dialog 'dd83810dbbdc72e4' in 6400 ms (Method: SUBSCRIBE)
[Mar 31 18:23:14] VERBOSE[4394] chan_sip.c: 
<--- SIP read from UDP:10.22.0.44:5060 --->
SUBSCRIBE sip:1731@10.22.1.201:5060 SIP/2.0
Accept: application/dialog-info+xml
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bKee164b85ae9870175
Max-Forwards: 70
From: <sip:1024@10.22.1.201:5060>;tag=9788a809d0
To: <sip:1731@10.22.1.201:5060>
Call-ID: dd83810dbbdc72e4
CSeq: 27153 SUBSCRIBE
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK, SUBSCRIBE, INFO
Allow-Events: aastra-xml, talk, hold, conference, LocalModeStatus
Authorization: Digest username="1024",realm="asterisk",nonce="4cca66a8",uri="sip:1731@10.22.1.201:5060",response="818034d089d75f0503832fc8ab6653ba",algorithm=MD5
Contact: <sip:1024@10.22.0.44:5060;transport=udp>
Event: dialog
Expires: 113
Supported: path
User-Agent: Aastra 55i/3.2.0.1011
Content-Length: 0


<------------->
[Mar 31 18:23:14] VERBOSE[4394] chan_sip.c: --- (17 headers 0 lines) ---
[Mar 31 18:23:14] VERBOSE[4394] chan_sip.c: Creating new subscription
[Mar 31 18:23:14] VERBOSE[4394] chan_sip.c: Sending to 10.22.0.44 : 5060 (NAT)
[Mar 31 18:23:14] VERBOSE[4394] chan_sip.c: Found peer '1024' for '1024' from 10.22.0.44:5060
[Mar 31 18:23:14] VERBOSE[4394] chan_sip.c: Looking for 1731 in from-internal (domain 10.22.1.201)
[Mar 31 18:23:14] VERBOSE[4394] chan_sip.c: 
<--- Transmitting (NAT) to 10.22.0.44:5060 --->
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bKee164b85ae9870175;received=10.22.0.44
From: <sip:1024@10.22.1.201:5060>;tag=9788a809d0
To: <sip:1731@10.22.1.201:5060>;tag=as474855fa
Call-ID: dd83810dbbdc72e4
CSeq: 27153 SUBSCRIBE
Server: Asterisk PBX 1.6.2.12
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0


<------------>

    And after that, every 19 secs :

    <--- SIP read from UDP:10.22.0.44:5060 --->
SUBSCRIBE sip:1731@10.22.1.201:5060 SIP/2.0
Accept: application/dialog-info+xml
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bKfb5d5d329444f3717
Max-Forwards: 70
From: <sip:1024@10.22.1.201:5060>;tag=90cdcd00b4
To: <sip:1731@10.22.1.201:5060>
Call-ID: c954ddf52a8346ee
CSeq: 24199 SUBSCRIBE
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK, SUBSCRIBE, INFO
Allow-Events: aastra-xml, talk, hold, conference, LocalModeStatus
Authorization: Digest username="1024",realm="asterisk",nonce="501a140e",uri="sip:1731@10.22.1.201:5060",response="879884f938bd76810f18aee40570435a",algorithm=MD5
Contact: <sip:1024@10.22.0.44:5060;transport=udp>
Event: dialog
Expires: 111
Supported: path
User-Agent: Aastra 55i/3.2.0.1011
Content-Length: 0


<------------->
[Mar 31 18:23:35] VERBOSE[4394] chan_sip.c: --- (17 headers 0 lines) ---
[Mar 31 18:23:35] VERBOSE[4394] chan_sip.c: Creating new subscription
[Mar 31 18:23:35] VERBOSE[4394] chan_sip.c: Sending to 10.22.0.44 : 5060 (NAT)
[Mar 31 18:23:35] VERBOSE[4394] chan_sip.c: list_route: hop: <sip:1024@10.22.0.44:5060;transport=udp>
[Mar 31 18:23:35] VERBOSE[4394] chan_sip.c: Found peer '1024' for '1024' from 10.22.0.44:5060
[Mar 31 18:23:35] VERBOSE[4394] chan_sip.c: 
<--- Transmitting (NAT) to 10.22.0.44:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bKfb5d5d329444f3717;received=10.22.0.44
From: <sip:1024@10.22.1.201:5060>;tag=90cdcd00b4
To: <sip:1731@10.22.1.201:5060>;tag=as5c38287e
Call-ID: c954ddf52a8346ee
CSeq: 24199 SUBSCRIBE
Server: Asterisk PBX 1.6.2.12
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="7bd6ef10"
Content-Length: 0


<------------>

    Questions :
    - why expiry is set to '113' at login and '111' after instead of '120' ?
    - why subscribe process did complete only once, ie 401 followed by 404 ?
    - why resubscribe every 19 sec ?

    Case 2b : USER 1731 login after USER 1614
    As before, each 19 secs DEVICE 1024 subscribe process did not complete, ie DEVICE 1024 did not reply to 401.

    Case 2c : USER 1614 logoff and login, USER 1731 still logged
    DEVICE 1024 subscribes to USER 1731 with expiry at '131' and then resubscribes every 116 secs.

    Case 2d : USER 1731 logoff before USER 1614

    <--- SIP read from UDP:10.22.0.44:5060 --->
SUBSCRIBE sip:1731@10.22.1.201 SIP/2.0
Accept: application/dialog-info+xml
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bK2ef112508a83cd144
Max-Forwards: 70
From: <sip:1024@10.22.1.201:5060>;tag=101779fdb3
To: <sip:1731@10.22.1.201:5060>;tag=as2317478e
Call-ID: 10eaafc51e63e17c
CSeq: 21129 SUBSCRIBE
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK, SUBSCRIBE, INFO
Allow-Events: aastra-xml, talk, hold, conference, LocalModeStatus
Authorization: Digest username="1024",realm="asterisk",nonce="6f5517a3",uri="sip:1731@10.22.1.201",response="0b02f84fc663c91fad9ca219f30bd75a",algorithm=MD5
Contact: <sip:1024@10.22.0.44:5060;transport=udp>
Event: dialog
Expires: 131
Supported: path
User-Agent: Aastra 55i/3.2.0.1011
Content-Length: 0


<------------->
[Apr  1 12:44:14] VERBOSE[4394] chan_sip.c: --- (17 headers 0 lines) ---
[Apr  1 12:44:14] VERBOSE[4394] chan_sip.c: Received resubscription for a dialog we no longer know about. Telling remote side to subscribe again.
[Apr  1 12:44:14] VERBOSE[4394] chan_sip.c: 
<--- Transmitting (NAT) to 10.22.0.44:5060 --->
SIP/2.0 481 Subscription does not exist
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bK2ef112508a83cd144;received=10.22.0.44
From: <sip:1024@10.22.1.201:5060>;tag=101779fdb3
To: <sip:1731@10.22.1.201:5060>;tag=as2317478e
Call-ID: 10eaafc51e63e17c
CSeq: 21129 SUBSCRIBE
Server: Asterisk PBX 1.6.2.12
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0


<------------>

    LED on DEVICE 1024 goes on, and after 40 secs :

    <--- SIP read from UDP:10.22.0.44:5060 --->
SUBSCRIBE sip:1731@10.22.1.201:5060 SIP/2.0
Accept: application/dialog-info+xml
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bK1eed6eb00b6ddadc3
Max-Forwards: 70
From: <sip:1024@10.22.1.201:5060>;tag=f55d918ba0
To: <sip:1731@10.22.1.201:5060>
Call-ID: 020b17529364ad44
CSeq: 9331 SUBSCRIBE
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK, SUBSCRIBE, INFO
Allow-Events: aastra-xml, talk, hold, conference, LocalModeStatus
Contact: <sip:1024@10.22.0.44:5060;transport=udp>
Event: dialog
Expires: 131
Supported: path
User-Agent: Aastra 55i/3.2.0.1011
Content-Length: 0


<------------->
[Apr  1 12:44:55] VERBOSE[4394] chan_sip.c: --- (16 headers 0 lines) ---
[Apr  1 12:44:55] VERBOSE[4394] chan_sip.c: Creating new subscription
[Apr  1 12:44:55] VERBOSE[4394] chan_sip.c: Sending to 10.22.0.44 : 5060 (NAT)
[Apr  1 12:44:55] VERBOSE[4394] chan_sip.c: list_route: hop: <sip:1024@10.22.0.44:5060;transport=udp>
[Apr  1 12:44:55] VERBOSE[4394] chan_sip.c: Found peer '1024' for '1024' from 10.22.0.44:5060
[Apr  1 12:44:55] VERBOSE[4394] chan_sip.c: 
<--- Transmitting (NAT) to 10.22.0.44:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bK1eed6eb00b6ddadc3;received=10.22.0.44
From: <sip:1024@10.22.1.201:5060>;tag=f55d918ba0
To: <sip:1731@10.22.1.201:5060>;tag=as0eb0eeb0
Call-ID: 020b17529364ad44
CSeq: 9331 SUBSCRIBE
Server: Asterisk PBX 1.6.2.12
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="287c5fd2"
Content-Length: 0


<------------>
[Apr  1 12:44:55] VERBOSE[4394] chan_sip.c: Scheduling destruction of SIP dialog '020b17529364ad44' in 6400 ms (Method: SUBSCRIBE)
[Apr  1 12:44:55] VERBOSE[4394] chan_sip.c: 
<--- SIP read from UDP:10.22.0.44:5060 --->
SUBSCRIBE sip:1731@10.22.1.201:5060 SIP/2.0
Accept: application/dialog-info+xml
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bK74e8d3ac88497cf80
Max-Forwards: 70
From: <sip:1024@10.22.1.201:5060>;tag=f55d918ba0
To: <sip:1731@10.22.1.201:5060>
Call-ID: 020b17529364ad44
CSeq: 9332 SUBSCRIBE
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK, SUBSCRIBE, INFO
Allow-Events: aastra-xml, talk, hold, conference, LocalModeStatus
Authorization: Digest username="1024",realm="asterisk",nonce="287c5fd2",uri="sip:1731@10.22.1.201:5060",response="bb06ded21c7067efa38b6421e78a0ebf",algorithm=MD5
Contact: <sip:1024@10.22.0.44:5060;transport=udp>
Event: dialog
Expires: 131
Supported: path
User-Agent: Aastra 55i/3.2.0.1011
Content-Length: 0


<------------->
[Apr  1 12:44:55] VERBOSE[4394] chan_sip.c: --- (17 headers 0 lines) ---
[Apr  1 12:44:55] VERBOSE[4394] chan_sip.c: Creating new subscription
[Apr  1 12:44:55] VERBOSE[4394] chan_sip.c: Sending to 10.22.0.44 : 5060 (NAT)
[Apr  1 12:44:55] VERBOSE[4394] chan_sip.c: Found peer '1024' for '1024' from 10.22.0.44:5060
[Apr  1 12:44:55] VERBOSE[4394] chan_sip.c: Looking for 1731 in from-internal (domain 10.22.1.201)
[Apr  1 12:44:55] VERBOSE[4394] chan_sip.c: 
<--- Transmitting (NAT) to 10.22.0.44:5060 --->
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bK74e8d3ac88497cf80;received=10.22.0.44
From: <sip:1024@10.22.1.201:5060>;tag=f55d918ba0
To: <sip:1731@10.22.1.201:5060>;tag=as0eb0eeb0
Call-ID: 020b17529364ad44
CSeq: 9332 SUBSCRIBE
Server: Asterisk PBX 1.6.2.12
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0


<------------>

    LED on DEVICE 1024 still lit, and then every 40 secs :

    <--- SIP read from UDP:10.22.0.44:5060 --->
SUBSCRIBE sip:1731@10.22.1.201:5060 SIP/2.0
Accept: application/dialog-info+xml
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bKa93dfd336929ed2fd
Max-Forwards: 70
From: <sip:1024@10.22.1.201:5060>;tag=f55d918ba0
To: <sip:1731@10.22.1.201:5060>
Call-ID: 020b17529364ad44
CSeq: 9333 SUBSCRIBE
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK, SUBSCRIBE, INFO
Allow-Events: aastra-xml, talk, hold, conference, LocalModeStatus
Authorization: Digest username="1024",realm="asterisk",nonce="287c5fd2",uri="sip:1731@10.22.1.201:5060",response="bb06ded21c7067efa38b6421e78a0ebf",algorithm=MD5
Contact: <sip:1024@10.22.0.44:5060;transport=udp>
Event: dialog
Expires: 131
Supported: path
User-Agent: Aastra 55i/3.2.0.1011
Content-Length: 0


<------------->
[Apr  1 12:45:36] VERBOSE[4394] chan_sip.c: --- (17 headers 0 lines) ---
[Apr  1 12:45:36] VERBOSE[4394] chan_sip.c: Creating new subscription
[Apr  1 12:45:36] VERBOSE[4394] chan_sip.c: Sending to 10.22.0.44 : 5060 (NAT)
[Apr  1 12:45:36] VERBOSE[4394] chan_sip.c: list_route: hop: <sip:1024@10.22.0.44:5060;transport=udp>
[Apr  1 12:45:36] VERBOSE[4394] chan_sip.c: Found peer '1024' for '1024' from 10.22.0.44:5060
[Apr  1 12:45:36] VERBOSE[4394] chan_sip.c: 
<--- Transmitting (NAT) to 10.22.0.44:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.22.0.44;branch=z9hG4bKa93dfd336929ed2fd;received=10.22.0.44
From: <sip:1024@10.22.1.201:5060>;tag=f55d918ba0
To: <sip:1731@10.22.1.201:5060>;tag=as278233ae
Call-ID: 020b17529364ad44
CSeq: 9333 SUBSCRIBE
Server: Asterisk PBX 1.6.2.12
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="07be67e0"
Content-Length: 0


<------------>

    Questions :
    - why LED still lit on DEVICE 1024 after 404 received?
    - why resubscribe every 40 sec ?
    - why resubscribe process did not complete, ie 401 not answered by DEVICE 1024 ?

    I realize that's a big post with a lot of debug to read and a lot of questions to answer, and I apologize for that.
    But I really need a fully functionnal BLF support for my customers.
    For me, that's sounds like a firmware's bug, let me know if I have to report in a bug tracker elsewhere.

    Regards,
    Bruno.



    Comment viewing options

    Select your preferred way to display the comments and click "Save settings" to activate your changes.