[asterisk-users] Problems w/Asterisk Realtime + MySQL + SIP

Tue Jul 22 03:46:11 CDT 2008

On Mon, Jul 21, 2008 at 6:40 PM, Walter Stanish
<walter at occidentsystems.com> wrote:
>>> [Jul 21 15:28:21] DEBUG[2028] chan_sip.c: **** Received REGISTER (2) -
>>> Command in SIP REGISTER
>>> [Jul 21 15:28:21] DEBUG[2028] chan_sip.c: SIP message could not be
>>> handled, bad request: ZjFhZjZlNmZmZjM3OWFlYzE0MGYzZDYwYzJmODAwNDg.
>>
>> It looks like Asterisk is unhappy with the SIP REGISTER request coming
>> from your softphone for some reason. It's very strange that it's
>> occurring for two different softphones though.
>>
>> Trun on SIP debugging by typing "sip debug" on your Asterisk console
>> and then post up the 4 SIP messages invloved in the register
>> transaction so we can take a look and spot why it could be getting
>> rejected.
>
> Sure.
>
> Here's what happens when kphone starts up:
>
> ==================================================
> <--- SIP read from 192.168.0.25:5060 --->
> REGISTER sip:192.168.0.2 SIP/2.0
> Via: SIP/2.0/UDP 192.168.0.25;branch=z9hG4bK5760BF8C
> CSeq: 35 REGISTER
> To: "Walter" <sip:walter at 192.168.0.2>
> Expires: 900
> From: "Walter" <sip:walter at 192.168.0.2>
> Call-ID: 1483331228 at 192.168.0.25
> Content-Length: 0
> User-Agent: kphone/4.2
> Event: registration
> Allow-Events: presence
> Contact: "Walter"
> <sip:walter at 192.168.0.25;transport=udp>;methods="INVITE, MESSAGE,
> INFO, SUBSCRIBE, OPTIONS, BYE, CANCEL, NOTIFY, ACK, REFER"
> black*CLI>
>
> <------------->
> --- (12 headers 0 lines) ---
> Using latest REGISTER request as basis request
> Sending to 192.168.0.25 : 5060 (no NAT)
>
> <--- Transmitting (no NAT) to 192.168.0.25:5060 --->
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP 192.168.0.25;branch=z9hG4bK5760BF8C;received=192.168.0.25
> From: "Walter" <sip:walter at 192.168.0.2>
> To: "Walter" <sip:walter at 192.168.0.2>
> Call-ID: 1483331228 at 192.168.0.25
> CSeq: 35 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:walter at 192.168.0.2>
> Content-Length: 0
>
>
> <------------>
>
> <--- Transmitting (no NAT) to 192.168.0.25:5060 --->
> SIP/2.0 401 Unauthorized
> Via: SIP/2.0/UDP 192.168.0.25;branch=z9hG4bK5760BF8C;received=192.168.0.25
> From: "Walter" <sip:walter at 192.168.0.2>
> To: "Walter" <sip:walter at 192.168.0.2>;tag=as59de1023
> Call-ID: 1483331228 at 192.168.0.25
> CSeq: 35 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="7864265a"
> Content-Length: 0
>
>
> <------------>
> Scheduling destruction of SIP dialog '1483331228 at 192.168.0.25' in
> 32000 ms (Method: REGISTER)
> ==================================================
>
> Kphone prompts for a password, then the following occurs.
>
> ==================================================
> <--- SIP read from 192.168.0.25:5060 --->
> REGISTER sip:192.168.0.2 SIP/2.0
> Via: SIP/2.0/UDP 192.168.0.25;branch=z9hG4bK36B0646C
> CSeq: 36 REGISTER
> To: "Walter" <sip:walter at 192.168.0.2>
> Authorization: Digest username="walter", realm="asterisk",
> nonce="7864265a", uri="sip:192.168.0.2", cnonce="abcdefghi",
> nc=00000001, response="10a7024959390c04b4d09c708fac6130", opaque="",
> algorithm="MD5"
> Expires: 900
> From: "Walter" <sip:walter at 192.168.0.2>
> Call-ID: 1483331228 at 192.168.0.25
> Content-Length: 0
> User-Agent: kphone/4.2
> Event: registration
> Allow-Events: presence
> Contact: "Walter"
> <sip:walter at 192.168.0.25;transport=udp>;methods="INVITE, MESSAGE,
> INFO, SUBSCRIBE, OPTIONS, BYE, CANCEL, NOTIFY, ACK, REFER"
>
>
> <------------->
> --- (13 headers 0 lines) ---
> Using latest REGISTER request as basis request
> Sending to 192.168.0.25 : 5060 (no NAT)
>
> <--- Transmitting (no NAT) to 192.168.0.25:5060 --->
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP 192.168.0.25;branch=z9hG4bK36B0646C;received=192.168.0.25
> From: "Walter" <sip:walter at 192.168.0.2>
> To: "Walter" <sip:walter at 192.168.0.2>
> Call-ID: 1483331228 at 192.168.0.25
> CSeq: 36 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:walter at 192.168.0.2>
> Content-Length: 0
>
>
> <------------>
>
> <--- Transmitting (no NAT) to 192.168.0.25:5060 --->
> SIP/2.0 403 Forbidden (Bad auth)
> Via: SIP/2.0/UDP 192.168.0.25;branch=z9hG4bK36B0646C;received=192.168.0.25
> From: "Walter" <sip:walter at 192.168.0.2>
> To: "Walter" <sip:walter at 192.168.0.2>;tag=as59de1023
> Call-ID: 1483331228 at 192.168.0.25
> CSeq: 36 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Content-Length: 0
>
>
> <------------>
> [Jul 22 00:59:38] NOTICE[2414]: chan_sip.c:15049
> handle_request_register: Registration from '"Walter"
> <sip:walter at 192.168.0.2>' failed for '192.168.0.25' - Wrong password
> Scheduling destruction of SIP dialog '1483331228 at 192.168.0.25' in
> 32000 ms (Method: REGISTER)
> Really destroying SIP dialog '1483331228 at 192.168.0.25' Method: REGISTER
> ==================================================
>
> Just to confirm, the password supplied was 'aaa'.
>
> In MySQL md5secret = md5('aaa') and secret = 'aaa'.
>
> Here's what happens with zoiper (one registration click only)...
> ==================================================
> <--- SIP read from 192.168.0.25:5060 --->
> REGISTER sip:192.168.0.2;transport=UDP SIP/2.0
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;rport
> Max-Forwards: 70
> Contact: <sip:walter@<snip>:5060;rinstance=592fe74defc7b295>;transport=UDP
> To: <sip:walter at 192.168.0.2>;transport=UDP
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> Expires: 3600
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO
> User-Agent: Zoiper rev.1075
> Allow-Events: presence
> Content-Length: 0
>
>
> <------------->
> --- (13 headers 0 lines) ---
> Using latest REGISTER request as basis request
> Sending to 192.168.0.25 : 5060 (NAT)
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:walter at 192.168.0.2>
> Content-Length: 0
>
>
> <------------>
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 401 Unauthorized
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP;tag=as6c5fed35
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="1a48c6f3"
> Content-Length: 0
>
>
> <------------>
> Scheduling destruction of SIP dialog
> 'ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.' in 32000 ms (Method:
> REGISTER)
> black*CLI>
> <--- SIP read from 192.168.0.25:5060 --->
> REGISTER sip:192.168.0.2;transport=UDP SIP/2.0
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;rport
> Max-Forwards: 70
> Contact: <sip:walter@<snip>:5060;rinstance=592fe74defc7b295>;transport=UDP
> To: <sip:walter at 192.168.0.2>;transport=UDP
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> Expires: 3600
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO
> User-Agent: Zoiper rev.1075
> Allow-Events: presence
> Content-Length: 0
>
>
> <------------->
> --- (13 headers 0 lines) ---
> Using latest REGISTER request as basis request
> Sending to 192.168.0.25 : 5060 (NAT)
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:walter at 192.168.0.2>
> Content-Length: 0
>
>
> <------------>
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 401 Unauthorized
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP;tag=as6c5fed35
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="1a48c6f3"
> Content-Length: 0
>
>
> <------------>
> Scheduling destruction of SIP dialog
> 'ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.' in 32000 ms (Method:
> REGISTER)
> black*CLI>
> <--- SIP read from 192.168.0.25:5060 --->
> REGISTER sip:192.168.0.2;transport=UDP SIP/2.0
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;rport
> Max-Forwards: 70
> Contact: <sip:walter@<snip>:5060;rinstance=592fe74defc7b295>;transport=UDP
> To: <sip:walter at 192.168.0.2>;transport=UDP
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> Expires: 3600
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO
> User-Agent: Zoiper rev.1075
> Allow-Events: presence
> Content-Length: 0
>
>
> <------------->
> --- (13 headers 0 lines) ---
> Using latest REGISTER request as basis request
> Sending to 192.168.0.25 : 5060 (NAT)
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:walter at 192.168.0.2>
> Content-Length: 0
>
>
> <------------>
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 401 Unauthorized
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP;tag=as6c5fed35
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="1a48c6f3"
> Content-Length: 0
>
>
> <------------>
> Scheduling destruction of SIP dialog
> 'ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.' in 32000 ms (Method:
> REGISTER)
> black*CLI>
> <--- SIP read from 192.168.0.25:5060 --->
> REGISTER sip:192.168.0.2;transport=UDP SIP/2.0
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;rport
> Max-Forwards: 70
> Contact: <sip:walter@<snip>:5060;rinstance=592fe74defc7b295>;transport=UDP
> To: <sip:walter at 192.168.0.2>;transport=UDP
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> Expires: 3600
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO
> User-Agent: Zoiper rev.1075
> Allow-Events: presence
> Content-Length: 0
>
>
> <------------->
> --- (13 headers 0 lines) ---
> Using latest REGISTER request as basis request
> Sending to 192.168.0.25 : 5060 (NAT)
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:walter at 192.168.0.2>
> Content-Length: 0
>
>
> <------------>
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 401 Unauthorized
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP;tag=as6c5fed35
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="1a48c6f3"
> Content-Length: 0
>
>
> <------------>
> Scheduling destruction of SIP dialog
> 'ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.' in 32000 ms (Method:
> REGISTER)
> black*CLI>
> <--- SIP read from 192.168.0.25:5060 --->
> REGISTER sip:192.168.0.2;transport=UDP SIP/2.0
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;rport
> Max-Forwards: 70
> Contact: <sip:walter@<snip>:5060;rinstance=592fe74defc7b295>;transport=UDP
> To: <sip:walter at 192.168.0.2>;transport=UDP
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> Expires: 3600
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO
> User-Agent: Zoiper rev.1075
> Allow-Events: presence
> Content-Length: 0
>
>
> <------------->
> --- (13 headers 0 lines) ---
> Using latest REGISTER request as basis request
> Sending to 192.168.0.25 : 5060 (NAT)
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:walter at 192.168.0.2>
> Content-Length: 0
>
>
> <------------>
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 401 Unauthorized
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP;tag=as6c5fed35
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="1a48c6f3"
> Content-Length: 0
>
>
> <------------>
> Scheduling destruction of SIP dialog
> 'ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.' in 32000 ms (Method:
> REGISTER)
> black*CLI>
> <--- SIP read from 192.168.0.25:5060 --->
> REGISTER sip:192.168.0.2;transport=UDP SIP/2.0
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;rport
> Max-Forwards: 70
> Contact: <sip:walter@<snip>:5060;rinstance=592fe74defc7b295>;transport=UDP
> To: <sip:walter at 192.168.0.2>;transport=UDP
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> Expires: 3600
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO
> User-Agent: Zoiper rev.1075
> Allow-Events: presence
> Content-Length: 0
>
>
> <------------->
> --- (13 headers 0 lines) ---
> Using latest REGISTER request as basis request
> Sending to 192.168.0.25 : 5060 (NAT)
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:walter at 192.168.0.2>
> Content-Length: 0
>
>
> <------------>
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 401 Unauthorized
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP;tag=as6c5fed35
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="1a48c6f3"
> Content-Length: 0
>
>
> <------------>
> Scheduling destruction of SIP dialog
> 'ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.' in 32000 ms (Method:
> REGISTER)
> black*CLI>
> <--- SIP read from 192.168.0.25:5060 --->
> REGISTER sip:192.168.0.2;transport=UDP SIP/2.0
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;rport
> Max-Forwards: 70
> Contact: <sip:walter@<snip>:5060;rinstance=592fe74defc7b295>;transport=UDP
> To: <sip:walter at 192.168.0.2>;transport=UDP
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> Expires: 3600
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO
> User-Agent: Zoiper rev.1075
> Allow-Events: presence
> Content-Length: 0
>
>
> <------------->
> --- (13 headers 0 lines) ---
> Using latest REGISTER request as basis request
> Sending to 192.168.0.25 : 5060 (NAT)
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:walter at 192.168.0.2>
> Content-Length: 0
>
>
> <------------>
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 401 Unauthorized
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP;tag=as6c5fed35
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="1a48c6f3"
> Content-Length: 0
>
>
> <------------>
> Scheduling destruction of SIP dialog
> 'ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.' in 32000 ms (Method:
> REGISTER)
> black*CLI>
> <--- SIP read from 192.168.0.25:5060 --->
> REGISTER sip:192.168.0.2;transport=UDP SIP/2.0
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;rport
> Max-Forwards: 70
> Contact: <sip:walter@<snip>:5060;rinstance=592fe74defc7b295>;transport=UDP
> To: <sip:walter at 192.168.0.2>;transport=UDP
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> Expires: 3600
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO
> User-Agent: Zoiper rev.1075
> Allow-Events: presence
> Content-Length: 0
>
>
> <------------->
> --- (13 headers 0 lines) ---
> Using latest REGISTER request as basis request
> Sending to 192.168.0.25 : 5060 (NAT)
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:walter at 192.168.0.2>
> Content-Length: 0
>
>
> <------------>
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 401 Unauthorized
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP;tag=as6c5fed35
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="1a48c6f3"
> Content-Length: 0
>
>
> <------------>
> Scheduling destruction of SIP dialog
> 'ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.' in 32000 ms (Method:
> REGISTER)
> black*CLI>
> <--- SIP read from 192.168.0.25:5060 --->
> REGISTER sip:192.168.0.2;transport=UDP SIP/2.0
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;rport
> Max-Forwards: 70
> Contact: <sip:walter@<snip>:5060;rinstance=592fe74defc7b295>;transport=UDP
> To: <sip:walter at 192.168.0.2>;transport=UDP
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> Expires: 3600
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO
> User-Agent: Zoiper rev.1075
> Allow-Events: presence
> Content-Length: 0
>
>
> <------------->
> --- (13 headers 0 lines) ---
> Using latest REGISTER request as basis request
> Sending to 192.168.0.25 : 5060 (NAT)
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:walter at 192.168.0.2>
> Content-Length: 0
>
>
> <------------>
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 401 Unauthorized
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP;tag=as6c5fed35
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="1a48c6f3"
> Content-Length: 0
>
>
> <------------>
> Scheduling destruction of SIP dialog
> 'ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.' in 32000 ms (Method:
> REGISTER)
> black*CLI>
> <--- SIP read from 192.168.0.25:5060 --->
> REGISTER sip:192.168.0.2;transport=UDP SIP/2.0
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;rport
> Max-Forwards: 70
> Contact: <sip:walter@<snip>:5060;rinstance=592fe74defc7b295>;transport=UDP
> To: <sip:walter at 192.168.0.2>;transport=UDP
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> Expires: 3600
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO
> User-Agent: Zoiper rev.1075
> Allow-Events: presence
> Content-Length: 0
>
>
> <------------->
> --- (13 headers 0 lines) ---
> Using latest REGISTER request as basis request
> Sending to 192.168.0.25 : 5060 (NAT)
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:walter at 192.168.0.2>
> Content-Length: 0
>
>
> <------------>
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 401 Unauthorized
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP;tag=as6c5fed35
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="1a48c6f3"
> Content-Length: 0
>
>
> <------------>
> Scheduling destruction of SIP dialog
> 'ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.' in 32000 ms (Method:
> REGISTER)
> black*CLI>
> <--- SIP read from 192.168.0.25:5060 --->
> REGISTER sip:192.168.0.2;transport=UDP SIP/2.0
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;rport
> Max-Forwards: 70
> Contact: <sip:walter@<snip>:5060;rinstance=592fe74defc7b295>;transport=UDP
> To: <sip:walter at 192.168.0.2>;transport=UDP
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> Expires: 3600
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO
> User-Agent: Zoiper rev.1075
> Allow-Events: presence
> Content-Length: 0
>
>
> <------------->
> --- (13 headers 0 lines) ---
> Using latest REGISTER request as basis request
> Sending to 192.168.0.25 : 5060 (NAT)
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:walter at 192.168.0.2>
> Content-Length: 0
>
>
> <------------>
>
> <--- Transmitting (no NAT) to <snip>:5060 --->
> SIP/2.0 401 Unauthorized
> Via: SIP/2.0/UDP
> <snip>:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;received=192.168.0.25;rport=5060
> From: <sip:walter at 192.168.0.2>;transport=UDP;tag=51db193e
> To: <sip:walter at 192.168.0.2>;transport=UDP;tag=as6c5fed35
> Call-ID: ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.
> CSeq: 3 REGISTER
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="1a48c6f3"
> Content-Length: 0
>
>
> <------------>
> Scheduling destruction of SIP dialog
> 'ODAwNjE1MDg0OTE3MGM3OGRhMDNlOTNjMGI5MzM1ZDk.' in 32000 ms (Method:
> REGISTER)
>
> ==================================================
>
> The <snip> IP is an external IP on our gateway machine - strangely
> enough this does not appear at all in the kphone sip debug console
> output, only in zoiper's.
>
> Hope the above is of some help...

Hi Walter,

I couldn't see any sign of the console message from your first trace
"[Jul 21 15:40:47] DEBUG[2105]: chan_sip.c:15372 sipsock_read: SIP
message could not be handled, bad request: 1832465624 at 192.168.0.25"
which is a bit strange.

The 403 Forbidden message you are getting with the KPHone is
definitely realted to credentials, either the username or password is
configured incorrectly somewhere. You can test by adding the SIP
account into sip.conf to get ti working and then after that move onto
your relatime config.

In regards to the Zoiper client it's sending the same REGISTER request
over and over again which typically means it is not receiving the
response being sent by Asterisk. The give away SIP headers are:

> Via: SIP/2.0/UDP ...:5060;branch=z9hG4bK-d8754z-9eb0f4d56eb2c53a-1---d8754z-;rport
> CSeq: 3 REGISTER

In the Via header case the branchid is unique for each new request and
in the CSeq case the number will increment with each new attempt.
Normally I'd suspect a misconfigured NAT in a case like this but it
looks like you are running ZOiper on the same LAN as your Asterisk
server so it must be some other config issue.

Regards,

Greyman.