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!:
localhostCLI> core set verbose 5
localhostCLI> core set debug 5
localhostCLI> module reload logger
localhostCLI> 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
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
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
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
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
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’.
localhostCLI>
localhostCLI>
localhostCLI>
localhostCLI>
localhostCLI>
localhostCLI>
localhostCLI>
[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’.
localhostCLI>
localhostCLI>
localhostCLI>
localhostCLI>
localhostCLI>
localhostCLI>
localhostCLI>
localhostCLI>
localhostCLI>
localhostCLI>
localhostCLI>
localhostCLI>
localhostCLI>
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
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!
localhostCLI> core set verbose 0
localhostCLI> core set debug 0
localhostCLI> sip set debug off
localhostCLI>
Console verbose was 5 and is now OFF.
Core debug was 5 and is now OFF.
SIP Debugging Disabled
localhostCLI>
localhostCLI>