# Not registered successfully for NAT case **URL:** \ **Category:** Asterisk Support\ **Created:** [January 4, 2015, 5:48am UTC](https://community.asterisk.org/t/not-registered-successfully-for-nat-case/47856 "2015-01-04T05:48:11Z")\ **Posts on this page:** 1\ **Page:** 1
**Author:** ![evers](https://avatars.discourse-cdn.com/v4/letter/e/8e7dd6/32.png) [@evers](https://community.asterisk.org/u/evers)\ **Post date:** [January 4, 2015, 5:48am UTC](https://community.asterisk.org/t/not-registered-successfully-for-nat-case/47856/1 "2015-01-04T05:48:11Z")
hi all, My asterisk is behind NAT, it works for the clients from inside NAT, both register and call works fine. the client shows: Endpoint: 8001/8001 Not in use 0 of inf InAuth: 8001-auth/8001 Aor: 8001 1 Contact: 8001/sip:8001@180.158.183.55:53502 Avail 16.242 for the Client from outside and another NAT, the register will not successful, but form the app it shows registered, and from asterisk peer, it shows: Endpoint: 8001/8001 Not in use 0 of inf InAuth: 8001-auth/8001 Aor: 8001 1 Contact: 8001/sip:8001@125.211.216.98:5060 Unavail 0.000 there’s Contact information although not successful, and i got some debug message for these failure registration as below, can anyone help to investigate it? thanks!: localhost_CLI\> core set verbose 5 localhost_CLI\> core set debug 5 localhost_CLI\> module reload logger localhost_CLI\> sip set debug on Console verbose was OFF and is now 5. Core debug was OFF and is now 5. Module ‘logger’ reloaded successfully. SIP Debugging enabled [2015-01-03 12:56:40] DEBUG[8113]: config.c:2039 config\_text\_file\_load: Parsing /etc/asterisk/logger.conf == Parsing ‘/etc/asterisk/logger.conf’: Found [2015-01-03 12:56:40] DEBUG[8113]: config.c:2039 config\_text\_file\_load: Parsing /etc/asterisk/logger\_general\_additional.conf == Parsing ‘/etc/asterisk/logger\_general\_additional.conf’: Found [2015-01-03 12:56:40] DEBUG[8113]: config.c:2039 config\_text\_file\_load: Parsing /etc/asterisk/logger\_general\_custom.conf == Parsing ‘/etc/asterisk/logger\_general\_custom.conf’: Found [2015-01-03 12:56:40] DEBUG[8113]: config.c:2039 config\_text\_file\_load: Parsing /etc/asterisk/logger\_logfiles\_additional.conf == Parsing ‘/etc/asterisk/logger\_logfiles\_additional.conf’: Found [2015-01-03 12:56:40] DEBUG[8113]: config.c:2039 config\_text\_file\_load: Parsing /etc/asterisk/logger\_logfiles\_custom.conf == Parsing ‘/etc/asterisk/logger\_logfiles\_custom.conf’: Found Asterisk Queue Logger restarted [2015-01-03 12:56:40] DEBUG[2463]: manager.c:5581 match\_filter: Examining AMI event: Event: Reload Privilege: system,all Module: logger Status: 0 [2015-01-03 12:56:42] DEBUG[2463]: manager.c:6021 process\_message: Running action ‘SIPpeers’ [2015-01-03 12:56:42] DEBUG[2463]: manager.c:6021 process\_message: Running action ‘IAXpeerlist’ [2015-01-03 12:56:42] DEBUG[2463]: manager.c:6021 process\_message: Running action ‘ExtensionState’ [2015-01-03 12:56:42] DEBUG[2463]: devicestate.c:364 \_ast\_device\_state: Checking if I can find provider for “Custom” - number: DND9001 [2015-01-03 12:56:42] DEBUG[2463]: devicestate.c:444 getproviderstate: Checking provider Custom with Custom [2015-01-03 12:56:42] DEBUG[2463]: db.c:376 db\_get\_common: Unable to find key ‘DND9001’ in family ‘CustomDevstate’ [2015-01-03 12:56:42] DEBUG[2463]: manager.c:6021 process\_message: Running action ‘ModuleCheck’ [2015-01-03 12:56:42] DEBUG[2463]: manager.c:5877 manager\_modulecheck: \*\*\*\* ModuleCheck .so file func\_presencestate.so [2015-01-03 12:56:42] DEBUG[2463]: manager.c:5884 manager\_modulecheck: \*\*\*\* ModuleCheck .c file func\_presencestate.c [2015-01-03 12:56:42] DEBUG[2463]: manager.c:6021 process\_message: Running action ‘Command’ [2015-01-03 12:56:42] DEBUG[2463]: manager.c:6021 process\_message: Running action ‘Status’ [2015-01-03 12:56:42] DEBUG[2463]: manager.c:6021 process\_message: Running action ‘QueueStatus’ [2015-01-03 12:56:42] DEBUG[2463]: manager.c:6021 process\_message: Running action ‘Command’ [2015-01-03 12:56:42] DEBUG[2463]: manager.c:6021 process\_message: Running action ‘ParkedCalls’ [2015-01-03 12:56:42] DEBUG[2463]: manager.c:6021 process\_message: Running action ‘Command’ [2015-01-03 12:56:42] DEBUG[2463]: manager.c:6021 process\_message: Running action ‘ConfbridgeListRooms’ \<— SIP read from UDP:125.211.216.98:53502 —\> \<-------------\> [2015-01-03 12:56:47] DEBUG[2237]: pjsip:0 \: sip\_endpoint.c Processing incoming message: Request msg OPTIONS/cseq=1395 (rdata0x7f5634002d18) [2015-01-03 12:56:47] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:56:47] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. [2015-01-03 12:56:47] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:56:47] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:56:47] DEBUG[8721]: pjsip:0 \: sip\_endpoint.c Distributing rdata to modules: Request msg OPTIONS/cseq=1395 (rdata0x7f56344a6fd8) [2015-01-03 12:56:47] DEBUG[8721]: res\_pjsip\_endpoint\_identifier\_user.c:104 username\_identify: Retrieved endpoint 8005 [2015-01-03 12:56:47] DEBUG[8721]: pjsip:0 \: endpoint .Response msg 401/OPTIONS/cseq=1395 (tdta0x7f5634005e80) created [2015-01-03 12:56:47] DEBUG[8721]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘192.168.1.107’ into… [2015-01-03 12:56:47] DEBUG[8721]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘192.168.1.107’ and port ‘’. [2015-01-03 12:56:47] DEBUG[8721]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98’ into… [2015-01-03 12:56:47] DEBUG[8721]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘’. [2015-01-03 12:56:47] DEBUG[8721]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:56:47] DEBUG[8721]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:56:47] DEBUG[8721]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:56:47] DEBUG[8721]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. [2015-01-03 12:56:47] DEBUG[2463]: manager.c:5581 match\_filter: Examining AMI event: Event: ChallengeSent Privilege: security,all EventTV: 2015-01-03T12:56:47.201+0800 Severity: Informational Service: PJSIP EventVersion: 1 AccountID: 8005 SessionID: [04da44a45996d34d38b65a38b9e0986e@192.168.8.101](mailto:04da44a45996d34d38b65a38b9e0986e@192.168.8.101) LocalAddress: IPV4/UDP/192.168.1.107/5060 RemoteAddress: IPV4/UDP/125.211.216.98/5060 Challenge: [2015-01-03 12:56:47] DEBUG[8721]: pjsip:0 \: tdta0x7f563400 .Destroying txdata Response msg 401/OPTIONS/cseq=1395 (tdta0x7f5634005e80) [2015-01-03 12:56:57] DEBUG[2237]: pjsip:0 \: sip\_endpoint.c Processing incoming message: Request msg OPTIONS/cseq=2980 (rdata0x7f5634002d18) [2015-01-03 12:56:57] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:56:57] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. [2015-01-03 12:56:57] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:56:57] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:56:57] DEBUG[2232]: pjsip:0 \: sip\_endpoint.c Distributing rdata to modules: Request msg OPTIONS/cseq=2980 (rdata0x7f56344a7f48) [2015-01-03 12:56:57] DEBUG[2232]: res\_pjsip\_endpoint\_identifier\_user.c:104 username\_identify: Retrieved endpoint 8005 [2015-01-03 12:56:57] DEBUG[2232]: pjsip:0 \: endpoint .Response msg 401/OPTIONS/cseq=2980 (tdta0x7f5634005e80) created [2015-01-03 12:56:57] DEBUG[2232]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘192.168.1.107’ into… [2015-01-03 12:56:57] DEBUG[2232]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘192.168.1.107’ and port ‘’. [2015-01-03 12:56:57] DEBUG[2232]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98’ into… [2015-01-03 12:56:57] DEBUG[2232]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘’. [2015-01-03 12:56:57] DEBUG[2232]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:56:57] DEBUG[2232]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:56:57] DEBUG[2463]: manager.c:5581 match\_filter: Examining AMI event: Event: ChallengeSent Privilege: security,all EventTV: 2015-01-03T12:56:57.140+0800 Severity: Informational Service: PJSIP EventVersion: 1 AccountID: 8005 SessionID: [e477d8e8101ba4d2190a78c494d4e263@192.168.8.101](mailto:e477d8e8101ba4d2190a78c494d4e263@192.168.8.101) LocalAddress: IPV4/UDP/192.168.1.107/5060 RemoteAddress: IPV4/UDP/125.211.216.98/5060 Challenge: [2015-01-03 12:56:57] DEBUG[2232]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:56:57] DEBUG[2232]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. [2015-01-03 12:56:57] DEBUG[2232]: pjsip:0 \: tdta0x7f563400 .Destroying txdata Response msg 401/OPTIONS/cseq=2980 (tdta0x7f5634005e80) [2015-01-03 12:57:01] DEBUG[12094]: manager.c:6021 process\_message: Running action ‘Login’ [2015-01-03 12:57:01] DEBUG[2463]: manager.c:5581 match\_filter: Examining AMI event: Event: SuccessfulAuth Privilege: security,all EventTV: 2015-01-03T12:57:01.435+0800 Severity: Informational Service: AMI EventVersion: 1 AccountID: admin SessionID: 0x7f5674008ab8 LocalAddress: IPV4/TCP/0.0.0.0/5038 RemoteAddress: IPV4/TCP/127.0.0.1/60661 UsingPassword: 0 SessionTV: 2015-01-03T12:57:01.435+0800 [2015-01-03 12:57:01] DEBUG[12094]: manager.c:6021 process\_message: Running action ‘Command’ [2015-01-03 12:57:01] DEBUG[12094]: manager.c:6021 process\_message: Running action ‘Command’ [2015-01-03 12:57:01] DEBUG[12094]: manager.c:6021 process\_message: Running action ‘Command’ [2015-01-03 12:57:01] DEBUG[12094]: manager.c:6021 process\_message: Running action ‘Command’ [2015-01-03 12:57:01] DEBUG[12094]: manager.c:6021 process\_message: Running action ‘Command’ [2015-01-03 12:57:01] DEBUG[12094]: manager.c:6021 process\_message: Running action ‘Command’ [2015-01-03 12:57:06] DEBUG[8721]: pjsip:0 \: endpoint Request msg OPTIONS/cseq=22242 (tdta0x7f5634565580) created. [2015-01-03 12:57:06] DEBUG[8721]: config.c:3483 ast\_parse\_arg: extract int from [0] in [-2147483648, 2147483647] gives 0 [2015-01-03 12:57:06] DEBUG[8721]: config.c:3483 ast\_parse\_arg: extract int from [0] in [-2147483648, 2147483647] gives 0 [2015-01-03 12:57:06] DEBUG[8721]: pjsip:0 \: tsx0x7f5640160 .Transaction created for Request msg OPTIONS/cseq=22242 (tdta0x7f5634565580) [2015-01-03 12:57:06] DEBUG[8721]: pjsip:0 \: tsx0x7f5640160 Sending Request msg OPTIONS/cseq=22242 (tdta0x7f5634565580) in state Null [2015-01-03 12:57:06] DEBUG[8721]: pjsip:0 \: sip\_resolve.c .Target ‘125.211.216.98:5060’ type=Unspecified resolved to ‘125.211.216.98:5060’ type=UDP (UDP transport) [2015-01-03 12:57:06] DEBUG[8721]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:57:06] DEBUG[8721]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:57:06] DEBUG[8721]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:57:06] DEBUG[8721]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. [2015-01-03 12:57:06] DEBUG[8721]: pjsip:0 \: tsx0x7f5640160 .State changed from Null to Calling, event=TX\_MSG [2015-01-03 12:57:06] DEBUG[11963]: threadpool.c:1107 worker\_idle: Worker thread idle timeout reached. Dying. [2015-01-03 12:57:06] DEBUG[2140]: threadpool.c:968 worker\_thread\_destroy: Destroying worker thread 114 [2015-01-03 12:57:07] DEBUG[2237]: pjsip:0 \: sip\_endpoint.c Processing incoming message: Request msg OPTIONS/cseq=9929 (rdata0x7f5634002d18) [2015-01-03 12:57:07] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:57:07] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. [2015-01-03 12:57:07] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:57:07] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:57:07] DEBUG[2232]: pjsip:0 \: sip\_endpoint.c Distributing rdata to modules: Request msg OPTIONS/cseq=9929 (rdata0x7f56344a8308) [2015-01-03 12:57:07] DEBUG[2232]: res\_pjsip\_endpoint\_identifier\_user.c:104 username\_identify: Retrieved endpoint 8005 [2015-01-03 12:57:07] DEBUG[2232]: pjsip:0 \: endpoint .Response msg 401/OPTIONS/cseq=9929 (tdta0x7f56b4034980) created [2015-01-03 12:57:07] DEBUG[2232]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘192.168.1.107’ into… [2015-01-03 12:57:07] DEBUG[2232]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘192.168.1.107’ and port ‘’. [2015-01-03 12:57:07] DEBUG[2232]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98’ into… [2015-01-03 12:57:07] DEBUG[2232]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘’. [2015-01-03 12:57:07] DEBUG[2232]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:57:07] DEBUG[2232]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:57:07] DEBUG[2232]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:57:07] DEBUG[2232]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. [2015-01-03 12:57:07] DEBUG[2463]: manager.c:5581 match\_filter: Examining AMI event: Event: ChallengeSent Privilege: security,all EventTV: 2015-01-03T12:57:07.140+0800 Severity: Informational Service: PJSIP EventVersion: 1 AccountID: 8005 SessionID: [55a3aa6115b3c7d9d00ff16dfa5818bf@192.168.8.101](mailto:55a3aa6115b3c7d9d00ff16dfa5818bf@192.168.8.101) LocalAddress: IPV4/UDP/192.168.1.107/5060 RemoteAddress: IPV4/UDP/125.211.216.98/5060 Challenge: [2015-01-03 12:57:07] DEBUG[2232]: pjsip:0 \: tdta0x7f56b403 .Destroying txdata Response msg 401/OPTIONS/cseq=9929 (tdta0x7f56b4034980) [2015-01-03 12:57:07] DEBUG[2237]: pjsip:0 \: tsx0x7f5640160 Retransmit timer event [2015-01-03 12:57:07] DEBUG[2237]: pjsip:0 \: tsx0x7f5640160 .Retransmiting Request msg OPTIONS/cseq=22242 (tdta0x7f5634565580), count=0, restart?=1 [2015-01-03 12:57:07] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:57:07] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:57:07] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:57:07] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. [2015-01-03 12:57:08] DEBUG[2237]: pjsip:0 \: tsx0x7f5640160 Retransmit timer event [2015-01-03 12:57:08] DEBUG[2237]: pjsip:0 \: tsx0x7f5640160 .Retransmiting Request msg OPTIONS/cseq=22242 (tdta0x7f5634565580), count=1, restart?=1 [2015-01-03 12:57:08] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:57:08] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:57:08] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:57:08] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. [2015-01-03 12:57:10] DEBUG[2237]: pjsip:0 \: tsx0x7f5640160 Retransmit timer event [2015-01-03 12:57:10] DEBUG[2237]: pjsip:0 \: tsx0x7f5640160 .Retransmiting Request msg OPTIONS/cseq=22242 (tdta0x7f5634565580), count=2, restart?=1 [2015-01-03 12:57:10] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:57:10] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:57:10] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:57:10] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. [2015-01-03 12:57:12] DEBUG[2237]: pjsip:0 \: sip\_endpoint.c Processing incoming message: Request msg OPTIONS/cseq=335 (rdata0x7f5634002d18) [2015-01-03 12:57:12] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:57:12] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. [2015-01-03 12:57:12] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:57:12] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:57:12] DEBUG[8721]: pjsip:0 \: sip\_endpoint.c Distributing rdata to modules: Request msg OPTIONS/cseq=335 (rdata0x7f56344a9268) [2015-01-03 12:57:12] DEBUG[8721]: res\_pjsip\_endpoint\_identifier\_user.c:104 username\_identify: Retrieved endpoint 8005 [2015-01-03 12:57:12] DEBUG[8721]: pjsip:0 \: endpoint .Response msg 401/OPTIONS/cseq=335 (tdta0x7f56b4034980) created [2015-01-03 12:57:12] DEBUG[8721]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘192.168.1.107’ into… [2015-01-03 12:57:12] DEBUG[8721]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘192.168.1.107’ and port ‘’. [2015-01-03 12:57:12] DEBUG[8721]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98’ into… [2015-01-03 12:57:12] DEBUG[8721]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘’. [2015-01-03 12:57:12] DEBUG[8721]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:57:12] DEBUG[8721]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:57:12] DEBUG[8721]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:57:12] DEBUG[8721]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. [2015-01-03 12:57:12] DEBUG[8721]: pjsip:0 \: tdta0x7f56b403 .Destroying txdata Response msg 401/OPTIONS/cseq=335 (tdta0x7f56b4034980) [2015-01-03 12:57:12] DEBUG[2463]: manager.c:5581 match\_filter: Examining AMI event: Event: ChallengeSent Privilege: security,all EventTV: 2015-01-03T12:57:12.460+0800 Severity: Informational Service: PJSIP EventVersion: 1 AccountID: 8005 SessionID: [5ada1f4e9c3cabc02d6994329d09a438@192.168.8.101](mailto:5ada1f4e9c3cabc02d6994329d09a438@192.168.8.101) LocalAddress: IPV4/UDP/192.168.1.107/5060 RemoteAddress: IPV4/UDP/125.211.216.98/5060 Challenge: [2015-01-03 12:57:14] DEBUG[2237]: pjsip:0 \: tsx0x7f5640160 Retransmit timer event [2015-01-03 12:57:14] DEBUG[2237]: pjsip:0 \: tsx0x7f5640160 .Retransmiting Request msg OPTIONS/cseq=22242 (tdta0x7f5634565580), count=3, restart?=1 [2015-01-03 12:57:14] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:57:14] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:57:14] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:57:14] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. \<— SIP read from UDP:125.211.216.98:53502 —\> \<-------------\> [2015-01-03 12:57:17] DEBUG[2237]: pjsip:0 \: sip\_endpoint.c Processing incoming message: Request msg OPTIONS/cseq=8495 (rdata0x7f5634002d18) [2015-01-03 12:57:17] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:57:17] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. [2015-01-03 12:57:17] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:57:17] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:57:17] DEBUG[2232]: pjsip:0 \: sip\_endpoint.c Distributing rdata to modules: Request msg OPTIONS/cseq=8495 (rdata0x7f56344a98b8) [2015-01-03 12:57:17] DEBUG[2232]: res\_pjsip\_endpoint\_identifier\_user.c:104 username\_identify: Retrieved endpoint 8005 [2015-01-03 12:57:17] DEBUG[2232]: pjsip:0 \: endpoint .Response msg 401/OPTIONS/cseq=8495 (tdta0x7f56b4034980) created [2015-01-03 12:57:17] DEBUG[2232]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘192.168.1.107’ into… [2015-01-03 12:57:17] DEBUG[2232]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘192.168.1.107’ and port ‘’. [2015-01-03 12:57:17] DEBUG[2232]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98’ into… [2015-01-03 12:57:17] DEBUG[2232]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘’. [2015-01-03 12:57:17] DEBUG[2232]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:57:17] DEBUG[2232]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:57:17] DEBUG[2232]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:57:17] DEBUG[2232]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. [2015-01-03 12:57:17] DEBUG[2463]: manager.c:5581 match\_filter: Examining AMI event: Event: ChallengeSent Privilege: security,all EventTV: 2015-01-03T12:57:17.152+0800 Severity: Informational Service: PJSIP EventVersion: 1 AccountID: 8005 SessionID: [d1fc20fad54616d79576e4fbf6847295@192.168.8.101](mailto:d1fc20fad54616d79576e4fbf6847295@192.168.8.101) LocalAddress: IPV4/UDP/192.168.1.107/5060 RemoteAddress: IPV4/UDP/125.211.216.98/5060 Challenge: [2015-01-03 12:57:17] DEBUG[2232]: pjsip:0 \: tdta0x7f56b403 .Destroying txdata Response msg 401/OPTIONS/cseq=8495 (tdta0x7f56b4034980) [2015-01-03 12:57:18] DEBUG[2237]: pjsip:0 \: tsx0x7f5640160 Retransmit timer event [2015-01-03 12:57:18] DEBUG[2237]: pjsip:0 \: tsx0x7f5640160 .Retransmiting Request msg OPTIONS/cseq=22242 (tdta0x7f5634565580), count=4, restart?=1 [2015-01-03 12:57:18] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:57:18] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:57:18] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:57:18] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. localhost_CLI\> localhost_CLI\> localhost_CLI\> localhost_CLI\> localhost_CLI\> localhost_CLI\> localhost_CLI\> [2015-01-03 12:57:22] DEBUG[2237]: pjsip:0 \: tsx0x7f5640160 Retransmit timer event [2015-01-03 12:57:22] DEBUG[2237]: pjsip:0 \: tsx0x7f5640160 .Retransmiting Request msg OPTIONS/cseq=22242 (tdta0x7f5634565580), count=5, restart?=1 [2015-01-03 12:57:22] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:57:22] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:57:22] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:57:22] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. localhost_CLI\> localhost_CLI\> localhost_CLI\> localhost_CLI\> localhost_CLI\> localhost_CLI\> localhost_CLI\> localhost_CLI\> localhost_CLI\> localhost_CLI\> localhost_CLI\> localhost_CLI\> localhost_CLI\> localhost\*CLI\> [2015-01-03 12:57:26] DEBUG[2237]: pjsip:0 \: tsx0x7f5640160 Retransmit timer event [2015-01-03 12:57:26] DEBUG[2237]: pjsip:0 \: tsx0x7f5640160 .Retransmiting Request msg OPTIONS/cseq=22242 (tdta0x7f5634565580), count=6, restart?=1 [2015-01-03 12:57:26] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:57:26] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:57:26] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:57:26] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. [2015-01-03 12:57:26] DEBUG[8721]: pjsip:0 \: endpoint Request msg OPTIONS/cseq=13160 (tdta0x7f5634005e80) created. [2015-01-03 12:57:26] DEBUG[8721]: config.c:3483 ast\_parse\_arg: extract int from [0] in [-2147483648, 2147483647] gives 0 [2015-01-03 12:57:26] DEBUG[8721]: config.c:3483 ast\_parse\_arg: extract int from [0] in [-2147483648, 2147483647] gives 0 [2015-01-03 12:57:26] DEBUG[8721]: pjsip:0 \: tsx0x7f56b0003 .Transaction created for Request msg OPTIONS/cseq=13160 (tdta0x7f5634005e80) [2015-01-03 12:57:26] DEBUG[8721]: pjsip:0 \: tsx0x7f56b0003 Sending Request msg OPTIONS/cseq=13160 (tdta0x7f5634005e80) in state Null [2015-01-03 12:57:26] DEBUG[8721]: pjsip:0 \: sip\_resolve.c .Target ‘192.168.1.109:5060’ type=Unspecified resolved to ‘192.168.1.109:5060’ type=UDP (UDP transport) [2015-01-03 12:57:26] DEBUG[8721]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:57:26] DEBUG[8721]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:57:26] DEBUG[8721]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘192.168.1.109:5060’ into… [2015-01-03 12:57:26] DEBUG[8721]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘192.168.1.109’ and port ‘5060’. [2015-01-03 12:57:26] DEBUG[8721]: pjsip:0 \: tsx0x7f56b0003 .State changed from Null to Calling, event=TX\_MSG [2015-01-03 12:57:26] DEBUG[2237]: pjsip:0 \: sip\_endpoint.c Processing incoming message: Response msg 200/OPTIONS/cseq=13160 (rdata0x7f5634002d18) [2015-01-03 12:57:26] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘192.168.1.109:5060’ into… [2015-01-03 12:57:26] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘192.168.1.109’ and port ‘5060’. [2015-01-03 12:57:26] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:57:26] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:57:26] DEBUG[2232]: pjsip:0 \: sip\_endpoint.c Distributing rdata to modules: Response msg 200/OPTIONS/cseq=13160 (rdata0x7f56344aa788) [2015-01-03 12:57:26] DEBUG[2232]: pjsip:0 \: tsx0x7f56b0003 .Incoming Response msg 200/OPTIONS/cseq=13160 (rdata0x7f56344aa788) in state Calling [2015-01-03 12:57:26] DEBUG[2232]: pjsip:0 \: tsx0x7f56b0003 …State changed from Calling to Completed, event=RX\_MSG [2015-01-03 12:57:26] DEBUG[2232]: config.c:3483 ast\_parse\_arg: extract int from [0] in [-2147483648, 2147483647] gives 0 [2015-01-03 12:57:26] DEBUG[2232]: config.c:3483 ast\_parse\_arg: extract int from [0] in [-2147483648, 2147483647] gives 0 [2015-01-03 12:57:27] DEBUG[2237]: pjsip:0 \: sip\_endpoint.c Processing incoming message: Request msg OPTIONS/cseq=4743 (rdata0x7f5634002d18) [2015-01-03 12:57:27] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:57:27] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. [2015-01-03 12:57:27] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:57:27] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:57:27] DEBUG[8721]: pjsip:0 \: sip\_endpoint.c Distributing rdata to modules: Request msg OPTIONS/cseq=4743 (rdata0x7f56344aab98) [2015-01-03 12:57:27] DEBUG[8721]: res\_pjsip\_endpoint\_identifier\_user.c:104 username\_identify: Retrieved endpoint 8005 [2015-01-03 12:57:27] DEBUG[8721]: pjsip:0 \: endpoint .Response msg 401/OPTIONS/cseq=4743 (tdta0x7f56b4004be0) created [2015-01-03 12:57:27] DEBUG[8721]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘192.168.1.107’ into… [2015-01-03 12:57:27] DEBUG[8721]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘192.168.1.107’ and port ‘’. [2015-01-03 12:57:27] DEBUG[8721]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98’ into… [2015-01-03 12:57:27] DEBUG[8721]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘’. [2015-01-03 12:57:27] DEBUG[8721]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:57:27] DEBUG[8721]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:57:27] DEBUG[8721]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:57:27] DEBUG[8721]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. [2015-01-03 12:57:27] DEBUG[8721]: pjsip:0 \: tdta0x7f56b400 .Destroying txdata Response msg 401/OPTIONS/cseq=4743 (tdta0x7f56b4004be0) [2015-01-03 12:57:27] DEBUG[2463]: manager.c:5581 match\_filter: Examining AMI event: Event: ChallengeSent Privilege: security,all EventTV: 2015-01-03T12:57:27.160+0800 Severity: Informational Service: PJSIP EventVersion: 1 AccountID: 8005 SessionID: [c56ebcf13a3ffc6bf1e9206d4b591309@192.168.8.101](mailto:c56ebcf13a3ffc6bf1e9206d4b591309@192.168.8.101) LocalAddress: IPV4/UDP/192.168.1.107/5060 RemoteAddress: IPV4/UDP/125.211.216.98/5060 Challenge: [2015-01-03 12:57:30] DEBUG[2237]: pjsip:0 \: tsx0x7f5640160 Retransmit timer event [2015-01-03 12:57:30] DEBUG[2237]: pjsip:0 \: tsx0x7f5640160 .Retransmiting Request msg OPTIONS/cseq=22242 (tdta0x7f5634565580), count=7, restart?=1 [2015-01-03 12:57:30] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘0.0.0.0:5060’ into… [2015-01-03 12:57:30] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘0.0.0.0’ and port ‘5060’. [2015-01-03 12:57:30] DEBUG[2237]: netsock2.c:172 ast\_sockaddr\_split\_hostport: Splitting ‘125.211.216.98:5060’ into… [2015-01-03 12:57:30] DEBUG[2237]: netsock2.c:226 ast\_sockaddr\_split\_hostport: …host ‘125.211.216.98’ and port ‘5060’. [2015-01-03 12:57:31] DEBUG[2237]: pjsip:0 \: tsx0x7f56b0003 Timeout timer event [2015-01-03 12:57:31] DEBUG[2237]: pjsip:0 \: tsx0x7f56b0003 .State changed from Completed to Terminated, event=TIMER [2015-01-03 12:57:31] DEBUG[2237]: pjsip:0 \: tsx0x7f56b0003 Timeout timer event [2015-01-03 12:57:31] DEBUG[2237]: pjsip:0 \: tsx0x7f56b0003 .State changed from Terminated to Destroyed, event=TIMER [2015-01-03 12:57:31] DEBUG[2237]: pjsip:0 \: tdta0x7f563400 …Destroying txdata Request msg OPTIONS/cseq=13160 (tdta0x7f5634005e80) [2015-01-03 12:57:31] DEBUG[2237]: pjsip:0 \: tsx0x7f56b0003 …Transaction destroyed! localhost_CLI\> core set verbose 0 localhost_CLI\> core set debug 0 localhost_CLI\> sip set debug off localhost_CLI\> Console verbose was 5 and is now OFF. Core debug was 5 and is now OFF. SIP Debugging Disabled localhost_CLI\> localhost_CLI\>