[Home]

Summary:ASTERISK-16062: chan_sip.c: Peer 'XXX' is now UNREACHABLE
Reporter:invitu (invitu)Labels:
Date Opened:2010-05-06 12:53:23Date Closed:2010-05-24 14:56:57
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/Registration
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) debug_60070.txt
Description:Hello,

I work with asterisk 1.6.1.18 (from fedora packages) behind a nat and hardphones (linksys SPA922-942 and siemens C470IP) which are behind different nats too. For testing, I also have a SPA942 on my LAN. Moreover, public IP are dynamic (because our unique ISP does not provide fixed IP addresses) but this is not the purpose for that issue because all worked very well for months.

Since several days, I have "unreachable" messages on the CLI that should not be due to NAT timeouts because I also have them with my LAN peer. Nothing has changed on my server and the problem appeared suddenly. For information, the problem occured twice this year with earlier asterisk versions and I don't know what resolved it.

Of course, during the time the peer is unreachable, it cannot be called which is a problem.

This time, I have debug information. Here are my confs & logs.

Regards


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

###########################################
sip config :
CLI> sip show settings
Global Settings:
----------------
 UDP SIP Port:           5060
 UDP Bindaddress:        0.0.0.0
 TCP SIP Port:           Disabled
 TLS SIP Port:           Disabled
 Videosupport:           No
 Textsupport:            No
 AutoCreate Peer:        No
 Ignore SDP sess. ver.:  No
 Match Auth Username:    No
 Allow unknown access:   Yes
 Allow subscriptions:    Yes
 Allow overlap dialing:  No
 Allow promsic. redir:   No
 Enable call counters:   No
 SIP domain support:     No
 Realm. auth:            No
 Our auth realm          asterisk
 Call to non-local dom.: Yes
 URI user is phone no:   No
 Always auth rejects:    No
 Direct RTP setup:       No
 User Agent:             QWERTY (not shown for security reasons)
 SDP Session Name:       Asterisk PBX 1.6.1.18
 SDP Owner Name:         root
 Reg. context:           (not set)
 Regexten on Qualify:    No
 Caller ID:              asterisk
 From: Domain:          
 Record SIP history:     Off
 Call Events:            Off
 Auth. Failure Events:   Off
 T.38 support:           No
 T.38 EC mode:           Unknown
 T.38 MaxDtgrm:          -1
 SIP realtime:           Disabled
 Qualify Freq :          60000 ms

Network QoS Settings:
---------------------------
 IP ToS SIP:             CS0
 IP ToS RTP audio:       CS0
 IP ToS RTP video:       CS0
 IP ToS RTP text:        CS0
 802.1p CoS SIP:         4
 802.1p CoS RTP audio:   5
 802.1p CoS RTP video:   6
 802.1p CoS RTP text:    5
 Jitterbuffer enabled:   No
 Jitterbuffer forced:    No
 Jitterbuffer max size:  -1
 Jitterbuffer resync:    -1
 Jitterbuffer impl:      
 Jitterbuffer log:       No

Network Settings:
---------------------------
 SIP address remapping:  Enabled using externhost
 Externhost:             myserver.mydomain.net (not shown for security reasons)
 Externip:               XXX.XXX.XXX.XXX:5060 (not shown for security reasons)
 Externrefresh:          10
 Internal IP:            127.0.0.1:5060
 Localnet:               192.168.0.0/255.255.255.0
 STUN server:            0.0.0.0:0
Global Signalling Settings:
---------------------------
 Codecs:                 0x8000e (gsm|ulaw|alaw|h263)
 Codec Order:            none
 Relax DTMF:             No
 RFC2833 Compensation:   No
 Compact SIP headers:    No
 RTP Keepalive:          0 (Disabled)
 RTP Timeout:            0 (Disabled)
 RTP Hold Timeout:       0 (Disabled)
 MWI NOTIFY mime type:   application/simple-message-summary
 DNS SRV lookup:         Yes
 Pedantic SIP support:   No
 Reg. min duration       60 secs
 Reg. max duration:      3600 secs
 Reg. default duration:  120 secs
 Outbound reg. timeout:  20 secs
 Outbound reg. attempts: 0
 Notify ringing state:   Yes
 Notify hold state:      No
 SIP Transfer mode:      open
 Max Call Bitrate:       384 kbps
 Auto-Framing:           No
 Outb. proxy:            <not set>
 Session Timers:         Accept
 Session Refresher:      uas
 Session Expires:        1800 secs
 Session Min-SE:         90 secs
 Timer T1:               500
 Timer T1 minimum:       100
 Timer B:                32000
 No premature media:     No

Default Settings:
-----------------
 Context:                default
 Nat:                    Always
 DTMF:                   rfc2833
 Qualify:                0
 Use ClientCode:         No
 Progress inband:        Never
 Language:              
 MOH Interpret:          default
 MOH Suggest:            
 Voice Mail Extension:   asterisk

####################
peer configuration (for behind nat peer) :

CLI> sip show peer 60070

 * Name       : 60070
 Secret       : <Not set>
 MD5Secret    : <Set>
 Context      : qwerty (not shown for security reasons)
 Subscr.Cont. : <Not set>
 Language     : fr
 Accountcode  : 123456789 (not shown for security reasons)
 AMA flags    : QWERTY (not shown for security reasons)
 Transfer mode: open
 CallingPres  : Presentation Allowed, Not Screened
 Callgroup    :  
 Pickupgroup  :
 Mailbox      : 60070
 VM Extension : asterisk
 LastMsgsSent : 32767/65535
 Call limit   : 0
 Dynamic      : Yes
 Callerid     : "" <60070>
 MaxCallBR    : 384 kbps
 Expire       : 177
 Insecure     : no
 Nat          : Always
 ACL          : No
 T.38 support : No
 T.38 EC mode : Unknown
 T.38 MaxDtgrm: -1
 CanReinvite  : No
 PromiscRedir : No
 User=Phone   : No
 Video Support: No
 Text Support : No
 Ign SDP ver  : No
 Trust RPID   : No
 Send RPID    : No
 Subscriptions: Yes
 Overlap dial : No
 DTMFmode     : rfc2833
 Timer T1     : 500
 Timer B      : 32000
 ToHost       :
 Addr->IP     : YYY.YYY.YYY.YYY Port 5918 (not shown for security reasons)
 Defaddr->IP  : 0.0.0.0 Port 5060
 Transport    : UDP
 Def. Username: 60070
 SIP Options  : (none)
 Codecs       : 0x100 (g729)
 Codec Order  : (g729:20)
 Auto-Framing :  No
 100 on REG   : No
 Status       : OK (165 ms)
 Useragent    : C470IP021910000000
 Reg. Contact : sip:60070@YYY.YYY.YYY.YYY:5918 (not shown for security reasons)
 Qualify Freq : 60000 ms
 Sess-Timers  : Accept
 Sess-Refresh : uas
 Sess-Expires : 1800 secs
 Min-Sess     : 90 secs
 Parkinglot   :

#############################
sip configuration (for LAN peer) :

CLI> sip show peer 60025


 * Name       : 60025
 Secret       : <Set>
 MD5Secret    : <Not set>
 Context      : qwerty (not shown for security reasons)
 Subscr.Cont. : <Not set>
 Language     : fr
 Accountcode  : 2468013579 (not shown for security reasons)
 AMA flags    : QWERTY (not shown for security reasons)
 Transfer mode: open
 CallingPres  : Presentation Allowed, Not Screened
 Callgroup    : 20
 Pickupgroup  : 20
 Mailbox      : 60025
 VM Extension : asterisk
 LastMsgsSent : 32767/65535
 Call limit   : 0
 Dynamic      : Yes
 Callerid     : "" <60025>
 MaxCallBR    : 384 kbps
 Expire       : 184
 Insecure     : no
 Nat          : Always
 ACL          : No
 T.38 support : No
 T.38 EC mode : Unknown
 T.38 MaxDtgrm: -1
 CanReinvite  : No
 PromiscRedir : No
 User=Phone   : No
 Video Support: No
 Text Support : No
 Ign SDP ver  : No
 Trust RPID   : No
 Send RPID    : No
 Subscriptions: Yes
 Overlap dial : No
 DTMFmode     : rfc2833
 Timer T1     : 500
 Timer B      : 32000
 ToHost       :
 Addr->IP     : 192.168.0.106 Port 5063
 Defaddr->IP  : 0.0.0.0 Port 5060
 Transport    : UDP
 Def. Username: 60025
 SIP Options  : (none)
 Codecs       : 0x100 (g729)
 Codec Order  : (g729:20)
 Auto-Framing :  No
 100 on REG   : No
 Status       : OK (8 ms)
 Useragent    : Linksys/SPA942-5.1.15(a)
 Reg. Contact : sip:60025@192.168.0.106:5063
 Qualify Freq : 60000 ms
 Sess-Timers  : Accept
 Sess-Refresh : uas
 Sess-Expires : 1800 secs
 Min-Sess     : 90 secs
 Parkinglot   :
#########################################
sip logs (for behind nat peer) :


[May  5 23:20:45] NOTICE[1847] chan_sip.c: Peer '60070' is now UNREACHABLE!  Last qualify: 122
[May  5 23:23:10] NOTICE[1847] chan_sip.c: Peer '60070' is now Reachable. (154ms / 2000ms)
[May  5 23:23:11] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"John Doe" <sip:60070@mydomain.net>'
[May  5 23:40:54] NOTICE[1847] chan_sip.c: Peer '60070' is now UNREACHABLE!  Last qualify: 141
[May  5 23:40:54] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"John Doe" <sip:60070@mydomain.net>'
[May  5 23:40:54] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"John Doe" <sip:60070@mydomain.net>'
[May  5 23:40:54] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"John Doe" <sip:60070@mydomain.net>'
[May  5 23:40:54] NOTICE[1847] chan_sip.c: Peer '60070' is now Reachable. (474ms / 2000ms)
[May  5 23:47:14] NOTICE[1847] chan_sip.c: Peer '60070' is now UNREACHABLE!  Last qualify: 1834
[May  5 23:47:50] NOTICE[1847] chan_sip.c: Peer '60070' is now Reachable. (124ms / 2000ms)
[May  5 23:53:09] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"John Doe" <sip:60070@mydomain.net>'
[May  5 23:53:09] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"John Doe" <sip:60070@mydomain.net>'
[May  5 23:53:09] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"John Doe" <sip:60070@mydomain.net>'
[May  5 23:54:39] NOTICE[1847] chan_sip.c: Peer '60070' is now UNREACHABLE!  Last qualify: 191
[May  5 23:55:28] NOTICE[1847] chan_sip.c: Peer '60070' is now Reachable. (121ms / 2000ms)
[May  6 00:15:38] NOTICE[1847] chan_sip.c: Peer '60070' is now UNREACHABLE!  Last qualify: 262
[May  6 00:15:51] NOTICE[1847] chan_sip.c: Peer '60070' is now Reachable. (313ms / 2000ms)
[May  6 00:20:00] NOTICE[1847] chan_sip.c: Peer '60070' is now UNREACHABLE!  Last qualify: 1915
[May  6 00:23:23] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"John Doe" <sip:60070@mydomain.net>'
[May  6 00:23:23] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"John Doe" <sip:60070@mydomain.net>'
[May  6 00:23:23] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"John Doe" <sip:60070@mydomain.net>'
[May  6 00:23:23] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"John Doe" <sip:60070@mydomain.net>'
[May  6 00:23:23] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"John Doe" <sip:60070@mydomain.net>'
[May  6 00:24:17] NOTICE[1847] chan_sip.c: Peer '60070' is now Reachable. (262ms / 2000ms)
##########################################
sip logs (for LAN peer):

[May  5 23:15:04] NOTICE[1847] chan_sip.c: Peer '60025' is now UNREACHABLE!  Last qualify: 6
[May  5 23:16:17] NOTICE[1847] chan_sip.c: Peer '60025' is now Reachable. (10ms / 2000ms)
[May  5 23:19:19] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:19:19] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:19:19] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:20:38] NOTICE[1847] chan_sip.c: Peer '60025' is now UNREACHABLE!  Last qualify: 13
[May  5 23:20:53] NOTICE[1847] chan_sip.c: Peer '60025' is now Reachable. (9ms / 2000ms)
[May  5 23:25:25] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:25:25] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:25:25] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:25:25] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:25:25] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:31:24] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:31:24] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:31:24] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:34:24] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:34:24] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:37:25] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:37:25] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:37:25] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:39:47] NOTICE[1847] chan_sip.c: Peer '60025' is now UNREACHABLE!  Last qualify: 7
[May  5 23:40:22] NOTICE[1847] chan_sip.c: Peer '60025' is now Reachable. (12ms / 2000ms)
[May  5 23:47:05] NOTICE[1847] chan_sip.c: Peer '60025' is now UNREACHABLE!  Last qualify: 9
[May  5 23:47:07] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:47:07] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:47:07] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:47:07] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:47:07] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:47:07] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:47:50] NOTICE[1847] chan_sip.c: Peer '60025' is now Reachable. (12ms / 2000ms)
[May  5 23:53:51] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:53:51] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:53:51] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:55:13] NOTICE[1847] chan_sip.c: Peer '60025' is now UNREACHABLE!  Last qualify: 13
[May  5 23:55:28] NOTICE[1847] chan_sip.c: Peer '60025' is now Reachable. (9ms / 2000ms)
[May  5 23:59:52] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:59:52] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  5 23:59:52] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  6 00:18:18] NOTICE[1847] chan_sip.c: Peer '60025' is now UNREACHABLE!  Last qualify: 6
[May  6 00:18:25] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  6 00:18:25] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  6 00:18:25] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  6 00:18:25] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  6 00:18:25] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  6 00:18:25] NOTICE[1847] chan_sip.c: Correct auth, but based on stale nonce received from '"60025" <sip:60025@192.168.0.204>'
[May  6 00:18:36] NOTICE[1847] chan_sip.c: Peer '60025' is now Reachable. (5ms / 2000ms)
##################
See more debug logs in attachment
Comments:By: Paul Belanger (pabelanger) 2010-05-06 13:21:52

Thanks for your comments. This does not appear to be a bug report and we are closing it. We appreciate the difficulties you are facing, but it would make more sense to raise your question in the support tracker, http://www.asterisk.org/support
By: invitu (invitu) 2010-05-21 07:14:44

Hello,

If you check the debug file in attachment, you will find some messages like:

chan_sip.c: SIP TIMER: Not rescheduling id #...:OPTIONS (Method 3) (No timer T1)

It appears that if the server does not receive a reply from the device, the timer T1 seems not being defined (it should be set to the round-trip time from the server to the peer)

Do you still think it is not a bug ?

Regards
By: Paul Belanger (pabelanger) 2010-05-24 14:56:57

This appears to be support related, not a bug. You will find more information about gaining support at http://www.asterisk.org/support

Also not 1.6.0 / 1.6.1 is only for security fixes only, I would suggest using 1.6.2 branch.