Connect. Communicate. Collaborate. Securely.

Home » Kerio User Forums » Kerio Operator » Loosing SIP trunks
  •  
djwyldeone

Messages: 15
Karma: 0
Send a private message to this user
I'm having a problem with the latest operator running on VMware where after a period of time its loosing the SIP truck connections for 2 different SIP trunk providers. After a I reset the telephony service it works for awhile and then stops again. There are no errors in the logs that I can see. Kinda stuck on this.


Troy

[Updated on: Thu, 30 May 2013 03:08]

  •  
djwyldeone

Messages: 15
Karma: 0
Send a private message to this user
I tried downgrading to 2.0 which is still getting the same problem.
  •  
silars

Messages: 429
Karma: 59
Send a private message to this user
Packet capture?

I'm using 2.1 on ESXi 5.1 with two SIP trunks to the same ITSP. I'm not seeing any issue.
  •  
djwyldeone

Messages: 15
Karma: 0
Send a private message to this user
Figured it out. It was a power settings issue on the vm which I was thinking might be the problem. Took off powersaving mode on the vm and it fixed the issue.
  •  
djwyldeone

Messages: 15
Karma: 0
Send a private message to this user
Ok this is still happening. It's loosing registration somehow. So here the log I have. This works when astrisk registers to the sip trunk but after a few minutes it looses registration and the call never gets to us.

This is debug with it registering and working. If I wait for say 10 or 15 minutes it will unregister and stop working.

[29/May/2013 20:11:10] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:8250 in find_call: = Looking for Call ID: watchdog@operator (Checking From) --From tag 55a66b --To-tag
[29/May/2013 20:11:10] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:25448 in handle_incoming: **** Received OPTIONS (3) - Command in SIP OPTIONS
[29/May/2013 20:11:10] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting 'operator' into...
[29/May/2013 20:11:10] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host 'operator' and port ''.
[29/May/2013 20:11:10] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting 'operator' into...
[29/May/2013 20:11:10] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host 'operator' and port ''.
[29/May/2013 20:11:10] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3412 in __sip_xmit: Trying to put 'SIP/2.0 404' onto UDP socket destined for 127.0.0.1:51838
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:8250 in find_call: = Looking for Call ID: 000f8f59-c6910002-2e839199-01fed2aa<_at_>192.168.1.115 (Checking From) --From tag 000f8f59c691000230260352-123d2a5a --To-tag
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: acl.c:736 in ast_ouraddrfor: For destination '192.168.1.115', our source address is '192.168.1.6'.
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3564 in ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 192.168.1.6:5060
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:7930 in sip_alloc: Allocating new SIP dialog for 000f8f59-c6910002-2e839199-01fed2aa<_at_>192.168.1.115 - REGISTER (No RTP)
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:25448 in handle_incoming: **** Received REGISTER (2) - Command in SIP REGISTER
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting '192.168.1.115:5060' into...
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host '192.168.1.115' and port '5060'.
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: Security.cpp:189 in int Security::authCheck(const sockaddr_in*, const char*): KerioSecurity check 192.168.1.115 (uri:<sip:103<_at_>192.168.1.6>).
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting '192.168.1.6' into...
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host '192.168.1.6' and port ''.
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3412 in __sip_xmit: Trying to put 'SIP/2.0 401' onto UDP socket destined for 192.168.1.115:5060
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:31115 in securityPostAuth: Kerio security: securityPostAuth - AUTH_CHALLENGE_SENT.
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:8250 in find_call: = Looking for Call ID: 000f8f59-c6910002-2e839199-01fed2aa<_at_>192.168.1.115 (Checking From) --From tag 000f8f59c691000230260352-123d2a5a --To-tag
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting '192.168.1.6' into...
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host '192.168.1.6' and port ''.
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting '192.168.1.6' into...
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host '192.168.1.6' and port ''.
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:25448 in handle_incoming: **** Received REGISTER (2) - Command in SIP REGISTER
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting '192.168.1.115:5060' into...
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host '192.168.1.115' and port '5060'.
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: Security.cpp:189 in int Security::authCheck(const sockaddr_in*, const char*): KerioSecurity check 192.168.1.115 (uri:<sip:103<_at_>192.168.1.6>).
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting '192.168.1.6' into...
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host '192.168.1.6' and port ''.
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:14281 in parse_register_contact: Store REGISTER's Contact header for call routing.
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting '192.168.1.115:5060' into...
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host '192.168.1.115' and port '5060'.
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3412 in __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.1.115:5060
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:7930 in sip_alloc: Allocating new SIP dialog for 19ee7cb8498bf2131d4eb0a2116e695a<_at_>127.0.0.1:5060 - NOTIFY (No RTP)
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: acl.c:736 in ast_ouraddrfor: For destination '192.168.1.115', our source address is '192.168.1.6'.
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3564 in ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 192.168.1.6:5060
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3088 in initialize_initreq: Initializing initreq for method NOTIFY - callid 7a1f93d017cf60701d56295f0a45c33b<_at_>192.168.1.6:5060
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3412 in __sip_xmit: Trying to put 'NOTIFY sip:' onto UDP socket destined for 192.168.1.115:5060
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:31111 in securityPostAuth: Kerio security: securityPostAuth - AUTH_SUCCESSFUL.
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: Security.cpp:300 in void Security::authSuccess(const sockaddr_in*, const char*): Asterisk: Host 192.168.1.115 authenticated (uri:<sip:103<_at_>192.168.1.6>).
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1634]: devicestate.c:342 in _ast_device_state: No provider found, checking channel drivers for SIP - 103
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1634]: chan_sip.c:26744 in sip_devicestate: Checking device state for peer 103
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1634]: devicestate.c:460 in do_state_change: Changing state for SIP/103 - state 1 (Not in use)
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1634]: devicestate.c:440 in devstate_event: device 'SIP/103' state '1'
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1635]: app_queue.c:1583 in extension_state_cb: Extension '103<_at_>sip-locals' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1815]: app_queue.c:1488 in handle_statechange: Device 'SIP/103' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:8250 in find_call: = Looking for Call ID: 7a1f93d017cf60701d56295f0a45c33b<_at_>192.168.1.6:5060 (Checking To) --From tag as7855b3ba --To-tag
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:4096 in __sip_ack: Stopping retransmission on '7a1f93d017cf60701d56295f0a45c33b<_at_>192.168.1.6:5060' of Request 102: Match Found
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:20745 in handle_response_notify: Got 200 accepted on NOTIFY 7a1f93d017cf60701d56295f0a45c33b<_at_>192.168.1.6:5060
[29/May/2013 20:11:13] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:6146 in sip_destroy: Destroying SIP dialog 7a1f93d017cf60701d56295f0a45c33b<_at_>192.168.1.6:5060
[29/May/2013 20:11:20] {asterisk}[1693] asteriskWatchdog: request:
[29/May/2013 20:11:20] {asterisk}OPTIONS sip:watchdog<_at_>operator SIP/2.0
[29/May/2013 20:11:20] {asterisk}Via: SIP/2.0 127.0.0.1:59201
[29/May/2013 20:11:20] {asterisk}From: <sip:watchdog@operator>;tag=55a66b
[29/May/2013 20:11:20] {asterisk}To: <sip:watchdog@operator>
[29/May/2013 20:11:20] {asterisk}Call-ID: watchdog@operator
[29/May/2013 20:11:20] {asterisk}CSeq: 735 OPTIONS
[29/May/2013 20:11:20] {asterisk}
[29/May/2013 20:11:20] {asterisk}[1693] asteriskWatchdog: response(384):
[29/May/2013 20:11:20] {asterisk}SIP/2.0 404 Not Found
[29/May/2013 20:11:20] {asterisk}Via: SIP/2.0 127.0.0.1:59201;received=127.0.0.1
[29/May/2013 20:11:20] {asterisk}From: <sip:watchdog@operator>;tag=55a66b
[29/May/2013 20:11:20] {asterisk}To: <sip:watchdog@operator>;tag=as4677427e
[29/May/2013 20:11:20] {asterisk}Call-ID: watchdog@operator
[29/May/2013 20:11:20] {asterisk}CSeq: 735 OPTIONS
[29/May/2013 20:11:20] {asterisk}Server: Asterisk PBX
[29/May/2013 20:11:20] {asterisk}Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[29/May/2013 20:11:20] {asterisk}Supported: replaces, timer
[29/May/2013 20:11:20] {asterisk}Accept: application/sdp
[29/May/2013 20:11:20] {asterisk}Content-Length: 0
[29/May/2013 20:11:20] {asterisk}
[29/May/2013 20:11:20] {asterisk}[1693] asteriskWatchdog: ONLINE
[29/May/2013 20:11:20] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:8250 in find_call: = Looking for Call ID: watchdog@operator (Checking From) --From tag 55a66b --To-tag
[29/May/2013 20:11:20] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:25448 in handle_incoming: **** Received OPTIONS (3) - Command in SIP OPTIONS
[29/May/2013 20:11:20] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting 'operator' into...
[29/May/2013 20:11:20] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host 'operator' and port ''.
[29/May/2013 20:11:20] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting 'operator' into...
[29/May/2013 20:11:20] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host 'operator' and port ''.
[29/May/2013 20:11:20] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3412 in __sip_xmit: Trying to put 'SIP/2.0 404' onto UDP socket destined for 127.0.0.1:59201
[29/May/2013 20:11:30] {asterisk}[1693] asteriskWatchdog: request:
[29/May/2013 20:11:30] {asterisk}OPTIONS sip:watchdog<_at_>operator SIP/2.0
[29/May/2013 20:11:30] {asterisk}Via: SIP/2.0 127.0.0.1:58434
[29/May/2013 20:11:30] {asterisk}From: <sip:watchdog@operator>;tag=55a66b
[29/May/2013 20:11:30] {asterisk}To: <sip:watchdog@operator>
[29/May/2013 20:11:30] {asterisk}Call-ID: watchdog@operator
[29/May/2013 20:11:30] {asterisk}CSeq: 736 OPTIONS
[29/May/2013 20:11:30] {asterisk}
[29/May/2013 20:11:30] {asterisk}[1693] asteriskWatchdog: response(384):
[29/May/2013 20:11:30] {asterisk}SIP/2.0 404 Not Found
[29/May/2013 20:11:30] {asterisk}Via: SIP/2.0 127.0.0.1:58434;received=127.0.0.1
[29/May/2013 20:11:30] {asterisk}From: <sip:watchdog@operator>;tag=55a66b
[29/May/2013 20:11:30] {asterisk}To: <sip:watchdog@operator>;tag=as4677427e
[29/May/2013 20:11:30] {asterisk}Call-ID: watchdog@operator
[29/May/2013 20:11:30] {asterisk}CSeq: 736 OPTIONS
[29/May/2013 20:11:30] {asterisk}Server: Asterisk PBX
[29/May/2013 20:11:30] {asterisk}Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[29/May/2013 20:11:30] {asterisk}Supported: replaces, timer
[29/May/2013 20:11:30] {asterisk}Accept: application/sdp
[29/May/2013 20:11:30] {asterisk}Content-Length: 0
[29/May/2013 20:11:30] {asterisk}
[29/May/2013 20:11:30] {asterisk}[1693] asteriskWatchdog: ONLINE
[29/May/2013 20:11:30] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:8250 in find_call: = Looking for Call ID: watchdog@operator (Checking From) --From tag 55a66b --To-tag
[29/May/2013 20:11:30] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:25448 in handle_incoming: **** Received OPTIONS (3) - Command in SIP OPTIONS
[29/May/2013 20:11:30] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting 'operator' into...
[29/May/2013 20:11:30] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host 'operator' and port ''.
[29/May/2013 20:11:30] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting 'operator' into...
[29/May/2013 20:11:30] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host 'operator' and port ''.
[29/May/2013 20:11:30] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3412 in __sip_xmit: Trying to put 'SIP/2.0 404' onto UDP socket destined for 127.0.0.1:58434
[29/May/2013 20:11:40] {asterisk}[1693] asteriskWatchdog: request:
[29/May/2013 20:11:40] {asterisk}OPTIONS sip:watchdog<_at_>operator SIP/2.0
[29/May/2013 20:11:40] {asterisk}Via: SIP/2.0 127.0.0.1:34482
[29/May/2013 20:11:40] {asterisk}From: <sip:watchdog@operator>;tag=55a66b
[29/May/2013 20:11:40] {asterisk}To: <sip:watchdog@operator>
[29/May/2013 20:11:40] {asterisk}Call-ID: watchdog@operator
[29/May/2013 20:11:40] {asterisk}CSeq: 737 OPTIONS
[29/May/2013 20:11:40] {asterisk}
[29/May/2013 20:11:40] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:8250 in find_call: = Looking for Call ID: watchdog@operator (Checking From) --From tag 55a66b --To-tag
[29/May/2013 20:11:40] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:25448 in handle_incoming: **** Received OPTIONS (3) - Command in SIP OPTIONS
[29/May/2013 20:11:40] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting 'operator' into...
[29/May/2013 20:11:40] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host 'operator' and port ''.
[29/May/2013 20:11:40] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting 'operator' into...
[29/May/2013 20:11:40] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host 'operator' and port ''.
[29/May/2013 20:11:40] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3412 in __sip_xmit: Trying to put 'SIP/2.0 404' onto UDP socket destined for 127.0.0.1:34482
[29/May/2013 20:11:40] {asterisk}[1693] asteriskWatchdog: response(384):
[29/May/2013 20:11:40] {asterisk}SIP/2.0 404 Not Found
[29/May/2013 20:11:40] {asterisk}Via: SIP/2.0 127.0.0.1:34482;received=127.0.0.1
[29/May/2013 20:11:40] {asterisk}From: <sip:watchdog@operator>;tag=55a66b
[29/May/2013 20:11:40] {asterisk}To: <sip:watchdog@operator>;tag=as4677427e
[29/May/2013 20:11:40] {asterisk}Call-ID: watchdog@operator
[29/May/2013 20:11:40] {asterisk}CSeq: 737 OPTIONS
[29/May/2013 20:11:40] {asterisk}Server: Asterisk PBX
[29/May/2013 20:11:40] {asterisk}Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[29/May/2013 20:11:40] {asterisk}Supported: replaces, timer
[29/May/2013 20:11:40] {asterisk}Accept: application/sdp
[29/May/2013 20:11:40] {asterisk}Content-Length: 0
[29/May/2013 20:11:40] {asterisk}
[29/May/2013 20:11:40] {asterisk}[1693] asteriskWatchdog: ONLINE
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3040 in registry_addref: SIP Registry sip.broadvoice.com: refcount now 3
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting 'sip.broadvoice.com' into...
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host 'sip.broadvoice.com' and port ''.
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting 'srv.bos.broadvoice.com' into...
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host 'srv.bos.broadvoice.com' and port ''.
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3032 in registry_unref: SIP Registry sip.broadvoice.com: refcount now 2
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:7930 in sip_alloc: Allocating new SIP dialog for 50e60b1f3940422b675cc2ce37421c96<_at_>sip.broadvoice.com - REGISTER (No RTP)
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3040 in registry_addref: SIP Registry sip.broadvoice.com: refcount now 3
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: acl.c:736 in ast_ouraddrfor: For destination '206.15.148.180', our source address is '192.168.1.6'.
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3564 in ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 192.168.1.6:5060
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3040 in registry_addref: SIP Registry sip.broadvoice.com: refcount now 4
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:13571 in transmit_register: Scheduled a registration timeout for sip.broadvoice.com id #2027
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting 'sip.broadvoice.com' into...
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host 'sip.broadvoice.com' and port ''.
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting 'sip.broadvoice.com' into...
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host 'sip.broadvoice.com' and port ''.
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3088 in initialize_initreq: Initializing initreq for method REGISTER - callid 50e60b1f3940422b675cc2ce37421c96<_at_>sip.broadvoice.com
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:13647 in transmit_register: REGISTER attempt 1 to 8153154009<_at_>sip.broadvoice.com
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3412 in __sip_xmit: Trying to put 'REGISTER si' onto UDP socket destined for 206.15.148.180:5060
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3032 in registry_unref: SIP Registry sip.broadvoice.com: refcount now 3
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:8250 in find_call: = Looking for Call ID: 50e60b1f3940422b675cc2ce37421c96<_at_>sip.broadvoice.com (Checking To) --From tag as087e5507 --To-tag
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:4096 in __sip_ack: Stopping retransmission on '50e60b1f3940422b675cc2ce37421c96<_at_>sip.broadvoice.com' of Request 107: Match Found
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:21041 in handle_response_register: Registration successful
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:21043 in handle_response_register: Cancelling timeout 2027
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3032 in registry_unref: SIP Registry sip.broadvoice.com: refcount now 2
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3032 in registry_unref: SIP Registry sip.broadvoice.com: refcount now 1
[29/May/2013 20:11:44] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3040 in registry_addref: SIP Registry sip.broadvoice.com: refcount now 2
[29/May/2013 20:11:45] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3952 in __sip_autodestruct: Auto destroying SIP dialog '000f8f59-c6910002-2e839199-01fed2aa<_at_>192.168.1.115'
[29/May/2013 20:11:45] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:6146 in sip_destroy: Destroying SIP dialog 000f8f59-c6910002-2e839199-01fed2aa<_at_>192.168.1.115
[29/May/2013 20:11:50] {asterisk}[1693] asteriskWatchdog: request:
[29/May/2013 20:11:50] {asterisk}OPTIONS sip:watchdog<_at_>operator SIP/2.0
[29/May/2013 20:11:50] {asterisk}Via: SIP/2.0 127.0.0.1:44707
[29/May/2013 20:11:50] {asterisk}From: <sip:watchdog@operator>;tag=55a66b
[29/May/2013 20:11:50] {asterisk}To: <sip:watchdog@operator>
[29/May/2013 20:11:50] {asterisk}Call-ID: watchdog@operator
[29/May/2013 20:11:50] {asterisk}CSeq: 738 OPTIONS
[29/May/2013 20:11:50] {asterisk}
[29/May/2013 20:11:50] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:8250 in find_call: = Looking for Call ID: watchdog@operator (Checking From) --From tag 55a66b --To-tag
[29/May/2013 20:11:50] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:25448 in handle_incoming: **** Received OPTIONS (3) - Command in SIP OPTIONS
[29/May/2013 20:11:50] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting 'operator' into...
[29/May/2013 20:11:50] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host 'operator' and port ''.
[29/May/2013 20:11:50] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting 'operator' into...
[29/May/2013 20:11:50] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host 'operator' and port ''.
[29/May/2013 20:11:50] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3412 in __sip_xmit: Trying to put 'SIP/2.0 404' onto UDP socket destined for 127.0.0.1:44707
[29/May/2013 20:11:50] {asterisk}[1693] asteriskWatchdog: response(384):
[29/May/2013 20:11:50] {asterisk}SIP/2.0 404 Not Found
[29/May/2013 20:11:50] {asterisk}Via: SIP/2.0 127.0.0.1:44707;received=127.0.0.1
[29/May/2013 20:11:50] {asterisk}From: <sip:watchdog@operator>;tag=55a66b
[29/May/2013 20:11:50] {asterisk}To: <sip:watchdog@operator>;tag=as4677427e
[29/May/2013 20:11:50] {asterisk}Call-ID: watchdog@operator
[29/May/2013 20:11:50] {asterisk}CSeq: 738 OPTIONS
[29/May/2013 20:11:50] {asterisk}Server: Asterisk PBX
[29/May/2013 20:11:50] {asterisk}Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[29/May/2013 20:11:50] {asterisk}Supported: replaces, timer
[29/May/2013 20:11:50] {asterisk}Accept: application/sdp
[29/May/2013 20:11:50] {asterisk}Content-Length: 0
[29/May/2013 20:11:50] {asterisk}
[29/May/2013 20:11:50] {asterisk}[1693] asteriskWatchdog: ONLINE
[29/May/2013 20:12:00] {asterisk}[1693] asteriskWatchdog: request:
[29/May/2013 20:12:00] {asterisk}OPTIONS sip:watchdog<_at_>operator SIP/2.0
[29/May/2013 20:12:00] {asterisk}Via: SIP/2.0 127.0.0.1:54558
[29/May/2013 20:12:00] {asterisk}From: <sip:watchdog@operator>;tag=55a66b
[29/May/2013 20:12:00] {asterisk}To: <sip:watchdog@operator>
[29/May/2013 20:12:00] {asterisk}Call-ID: watchdog@operator
[29/May/2013 20:12:00] {asterisk}CSeq: 739 OPTIONS
[29/May/2013 20:12:00] {asterisk}
[29/May/2013 20:12:00] {asterisk}[1693] asteriskWatchdog: response(384):
[29/May/2013 20:12:00] {asterisk}SIP/2.0 404 Not Found
[29/May/2013 20:12:00] {asterisk}Via: SIP/2.0 127.0.0.1:54558;received=127.0.0.1
[29/May/2013 20:12:00] {asterisk}From: <sip:watchdog@operator>;tag=55a66b
[29/May/2013 20:12:00] {asterisk}To: <sip:watchdog@operator>;tag=as4677427e
[29/May/2013 20:12:00] {asterisk}Call-ID: watchdog@operator
[29/May/2013 20:12:00] {asterisk}CSeq: 739 OPTIONS
[29/May/2013 20:12:00] {asterisk}Server: Asterisk PBX
[29/May/2013 20:12:00] {asterisk}Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[29/May/2013 20:12:00] {asterisk}Supported: replaces, timer
[29/May/2013 20:12:00] {asterisk}Accept: application/sdp
[29/May/2013 20:12:00] {asterisk}Content-Length: 0
[29/May/2013 20:12:00] {asterisk}
[29/May/2013 20:12:00] {asterisk}[1693] asteriskWatchdog: ONLINE
[29/May/2013 20:12:00] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:8250 in find_call: = Looking for Call ID: watchdog@operator (Checking From) --From tag 55a66b --To-tag
[29/May/2013 20:12:00] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:25448 in handle_incoming: **** Received OPTIONS (3) - Command in SIP OPTIONS
[29/May/2013 20:12:00] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting 'operator' into...
[29/May/2013 20:12:00] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host 'operator' and port ''.
[29/May/2013 20:12:00] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting 'operator' into...
[29/May/2013 20:12:00] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host 'operator' and port ''.
[29/May/2013 20:12:00] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3412 in __sip_xmit: Trying to put 'SIP/2.0 404' onto UDP socket destined for 127.0.0.1:54558
[29/May/2013 20:12:10] {asterisk}[1693] asteriskWatchdog: request:
[29/May/2013 20:12:10] {asterisk}OPTIONS sip:watchdog<_at_>operator SIP/2.0
[29/May/2013 20:12:10] {asterisk}Via: SIP/2.0 127.0.0.1:36916
[29/May/2013 20:12:10] {asterisk}From: <sip:watchdog@operator>;tag=55a66b
[29/May/2013 20:12:10] {asterisk}To: <sip:watchdog@operator>
[29/May/2013 20:12:10] {asterisk}Call-ID: watchdog@operator
[29/May/2013 20:12:10] {asterisk}CSeq: 740 OPTIONS
[29/May/2013 20:12:10] {asterisk}
[29/May/2013 20:12:10] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:8250 in find_call: = Looking for Call ID: watchdog@operator (Checking From) --From tag 55a66b --To-tag
[29/May/2013 20:12:10] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:25448 in handle_incoming: **** Received OPTIONS (3) - Command in SIP OPTIONS
[29/May/2013 20:12:10] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting 'operator' into...
[29/May/2013 20:12:10] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host 'operator' and port ''.
[29/May/2013 20:12:10] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:138 in ast_sockaddr_split_hostport: Splitting 'operator' into...
[29/May/2013 20:12:10] {asterisk} asterisk[1627]: DEBUG[1775]: netsock2.c:192 in ast_sockaddr_split_hostport: ...host 'operator' and port ''.
[29/May/2013 20:12:10] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3412 in __sip_xmit: Trying to put 'SIP/2.0 404' onto UDP socket destined for 127.0.0.1:36916
[29/May/2013 20:12:10] {asterisk}[1693] asteriskWatchdog: response(384):
[29/May/2013 20:12:10] {asterisk}SIP/2.0 404 Not Found
[29/May/2013 20:12:10] {asterisk}Via: SIP/2.0 127.0.0.1:36916;received=127.0.0.1
[29/May/2013 20:12:10] {asterisk}From: <sip:watchdog@operator>;tag=55a66b
[29/May/2013 20:12:10] {asterisk}To: <sip:watchdog@operator>;tag=as4677427e
[29/May/2013 20:12:10] {asterisk}Call-ID: watchdog@operator
[29/May/2013 20:12:10] {asterisk}CSeq: 740 OPTIONS
[29/May/2013 20:12:10] {asterisk}Server: Asterisk PBX
[29/May/2013 20:12:10] {asterisk}Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[29/May/2013 20:12:10] {asterisk}Supported: replaces, timer
[29/May/2013 20:12:10] {asterisk}Accept: application/sdp
[29/May/2013 20:12:10] {asterisk}Content-Length: 0
[29/May/2013 20:12:10] {asterisk}
[29/May/2013 20:12:10] {asterisk}[1693] asteriskWatchdog: ONLINE
[29/May/2013 20:12:16] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:3952 in __sip_autodestruct: Auto destroying SIP dialog '50e60b1f3940422b675cc2ce37421c96<_at_>sip.broadvoice.com'
[29/May/2013 20:12:16] {asterisk} asterisk[1627]: DEBUG[1775]: chan_sip.c:6146 in sip_destro
  •  
djwyldeone

Messages: 15
Karma: 0
Send a private message to this user
Ok found the problem on this just in case someone else has this problem. the problem is with Asterisk and the Sonicwall firewall. UDP time is default set to 30 seconds on Sonicwall and Asterisk default UDP time is 60 seconds. So switching UDP to 90 seconds solved the problem. Heres a link for future reference.


http://www.informaticapressapochista.com/asterisk/asterisk-w ith-sonicwall/
  •  
giampos

Messages: 187
Karma: 2
Send a private message to this user
I have a similar problem with Operator and Control, after some days sip interface loose registration, in the call routing section - incoming interfaces, I can see a yellow triangle on the sip interface. Only outgoing calls go.
Incoming calls are blocked. If I click "refresh" button nothing happens.
I have to edit sip interface, disable it and confirm.....then re-edit interface and enable it.
In this case the interface is registered.
The biggest problem is that no messages and alerts are sent and may happen not to receive calls for a few days.
Previous Topic: Lync-KOP-Alcatel
Next Topic: Kerio Softphone connecting via VPN
Goto Forum:
  


Disclaimer:
Kerio discussion forums are intended for open communication between forum members and may contain information and material posted by members which may be useful in learning about Kerio products. The discussion forums are not intended to provide technical support for any specific product. Any information implied or expressed in the discussion forums is that of the posting member. Kerio is in no way responsible for the information posted in the forums, or its accuracy. Kerio employees may participate in the discussions, but their postings do not represent an offical position of the company on any issues raised or discussed. Kerio reserves the right to monitor and maintain the forums to promote free and accurate exchange of information.

Current Time: Thu Aug 17 23:29:09 CEST 2017

Total time taken to generate the page: 0.00440 seconds
.:: Contact :: Home ::.
Powered by: FUDforum 3.0.4.