Thanks. I have attached a text file as its a bit long to paste in a message and there are long lines.

Looking through the log these couple of entries look significant.

DBG:auth:build_auth_hf: 'Proxy-Authenticate: Digest realm="vmopensips1.skycomuk.com", nonce="4d26db6600000001d69ce33126031746bdf4735e3f0f922d"
...
DBG:tm:matching_3261: RFC3261 transaction matching failed




Bogdan-Andrei Iancu wrote:
Hi Gareth,

hard to say without some logs - do you see errors in the opensips log ? if not, increase the debug level to 6 and post the logs corresponding the call.

Regards,
Bogdan

Gareth Blades wrote:
Setup:-
Server installed at a hosting facility with its owm public IP address.
A desk phone in the office with a couple of accounts configured registered to opensips through a NAT firewall. The opensips server has been installed and configured using the guide in the Opensips PACT book together with database support (no multidomain).

The two lines on the phone are able to register fine and I can see them as being registered in the database and 'opensipsctrl ul show' displays what I would expect.

However when I call between the two lines and minitoring via ngrep I see the initial INVITE go out and then a '407 proxy authentication required' comes back and the phone sends the invite again with the authentication but opensips doesnt send any reply. The phone retransmits the packet a couple of times and displays call failed.

Any idea what may be wrong?


I know the call audio is unlikely to work but that will be the next step. I am just trying to get each step working as I go at the moment.


Thanks
Gareth

_______________________________________________
Users mailing list
[email protected]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users




Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_msg: SIP 
Request: 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_msg:  method: 
 <INVITE> 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_msg:  uri:    
 <sip:[email protected]:5060> 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_msg:  
version: <SIP/2.0> 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: 
flags=2 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_via_param: 
found param type 232, <branch> = <z9hG4bK1f688db07e3542d3a>; state=16 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_via: end of 
header reached, state=5 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: via 
found, flags=2 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: this 
is the first via 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:receive_msg: After 
parse_msg... 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:receive_msg: 
preparing to run routing scripts... 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: 
flags=100 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: 
DBG:maxfwd:is_maxfwd_present: value = 70  
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: 
flags=8 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_to: end of 
header reached, state=10 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_to: 
display={"1001"}, ruri={sip:[email protected]:5060} 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: <To> 
[49]; uri=[sip:[email protected]:5060]  
 ]   7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: to 
body ["1001" <sip:[email protected]:5060>
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:uri:has_totag: no totag 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: 
flags=78 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: cseq 
<CSeq>: <6436> <INVITE> 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:tm:t_lookup_request: 
start searching: hash=16284, isACK=0 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:tm:matching_3261: 
RFC3261 transaction matching failed 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_msg: SIP 
Request: 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:tm:t_lookup_request: no 
transaction found 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_msg:  method: 
 <INVITE> 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_to_param: 
tag=6392ae5f12 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_msg:  uri:    
 <sip:[email protected]:5060> 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_to: end of 
header reached, state=29 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_msg:  
version: <SIP/2.0> 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_to: 
display={"1000"}, ruri={sip:[email protected]:5060} 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_headers: 
flags=2 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: 
checking if host==us: 24==9 &&  [vmopensips1.skycomuk.com] == [127.0.0.1] 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_via_param: 
found param type 232, <branch> = <z9hG4bK1f688db07e3542d3a>; state=16 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_via: end of 
header reached, state=5 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: 
checking if host==us: 24==11 &&  [vmopensips1.skycomuk.com] == [10.150.0.33] 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_headers: via 
found, flags=2 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_headers: this 
is the first via 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: 
checking if host==us: 24==13 &&  [vmopensips1.skycomuk.com] == [212.84.166.33] 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20836]: DBG:core:receive_msg: After 
parse_msg... 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20836]: DBG:core:receive_msg: 
preparing to run routing scripts... 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: 
checking if host==us: 24==9 &&  [vmopensips1.skycomuk.com] == [127.0.0.1] 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_msg: SIP 
Request: 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_headers: 
flags=100 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_msg:  method: 
 <INVITE> 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20836]: 
DBG:maxfwd:is_maxfwd_present: value = 70  
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: 
checking if host==us: 24==11 &&  [vmopensips1.skycomuk.com] == [10.150.0.33] 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_msg:  uri:    
 <sip:[email protected]:5060> 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_headers: 
flags=8 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_msg:  
version: <SIP/2.0> 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_to: end of 
header reached, state=10 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: 
checking if host==us: 24==13 &&  [vmopensips1.skycomuk.com] == [212.84.166.33] 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_headers: 
flags=2 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_to: 
display={"1001"}, ruri={sip:[email protected]:5060} 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_via_param: 
found param type 232, <branch> = <z9hG4bK1f688db07e3542d3a>; state=16 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20836]: DBG:core:get_hdr_field: <To> 
[49]; uri=[sip:[email protected]:5060]  
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: 
flags=10000 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_via: end of 
header reached, state=5 
 ]   7 09:22:11 vmopensips1 /sbin/opensips[20836]: DBG:core:get_hdr_field: to 
body ["1001" <sip:[email protected]:5060>
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: 
content_length=595 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_headers: via 
found, flags=2 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20836]: DBG:uri:has_totag: no totag 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: 
found end of header 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_headers: this 
is the first via 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_headers: 
flags=78 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20835]: DBG:auth:pre_auth: 
credentials with given realm not found 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20837]: DBG:core:receive_msg: After 
parse_msg... 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20836]: DBG:core:get_hdr_field: cseq 
<CSeq>: <6436> <INVITE> 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20835]: 
DBG:auth:reserve_nonce_index: second= 1, sec_monit= -1,  index= 0 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20837]: DBG:core:receive_msg: 
preparing to run routing scripts... 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20836]: DBG:tm:t_lookup_request: 
start searching: hash=16284, isACK=0 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20835]: DBG:auth:build_auth_hf: 
nonce index= 0 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_headers: 
flags=100 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20836]: DBG:tm:matching_3261: 
RFC3261 transaction matching failed 
 '   7 09:22:12 vmopensips1 /sbin/opensips[20835]: DBG:auth:build_auth_hf: 
'Proxy-Authenticate: Digest realm="vmopensips1.skycomuk.com", 
nonce="4d26db62000000005a481811987f903105543127c6b1e8ff"
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20837]: 
DBG:maxfwd:is_maxfwd_present: value = 70  
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20836]: DBG:tm:t_lookup_request: no 
transaction found 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: 
flags=ffffffffffffffff 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_headers: 
flags=8 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_to_param: 
tag=6392ae5f12 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20835]: DBG:core:check_ip_address: 
params 212.84.170.85, 212.84.170.85, 0 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_msg: SIP 
Request: 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_to: end of 
header reached, state=10 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_to: end of 
header reached, state=29 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20835]: DBG:core:destroy_avp_list: 
destroying list (nil) 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_msg:  method: 
 <INVITE> 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_to: 
display={"1001"}, ruri={sip:[email protected]:5060} 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_to: 
display={"1000"}, ruri={sip:[email protected]:5060} 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20835]: DBG:core:receive_msg: 
cleaning up 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_msg:  uri:    
 <sip:[email protected]:5060> 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20837]: DBG:core:get_hdr_field: <To> 
[49]; uri=[sip:[email protected]:5060]  
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: 
checking if host==us: 24==9 &&  [vmopensips1.skycomuk.com] == [127.0.0.1] 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_msg: SIP 
Request: 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_msg:  
version: <SIP/2.0> 
 ]   7 09:22:13 vmopensips1 /sbin/opensips[20837]: DBG:core:get_hdr_field: to 
body ["1001" <sip:[email protected]:5060>
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_msg:  method: 
 <ACK> 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_headers: 
flags=2 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20837]: DBG:uri:has_totag: no totag 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: 
checking if host==us: 24==11 &&  [vmopensips1.skycomuk.com] == [10.150.0.33] 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_msg:  uri:    
 <sip:[email protected]:5060> 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_via_param: 
found param type 232, <branch> = <z9hG4bK1f688db07e3542d3a>; state=16 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_headers: 
flags=78 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_msg:  
version: <SIP/2.0> 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_via: end of 
header reached, state=5 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20837]: DBG:core:get_hdr_field: cseq 
<CSeq>: <6436> <INVITE> 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: 
checking if host==us: 24==13 &&  [vmopensips1.skycomuk.com] == [212.84.166.33] 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: 
flags=2 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_headers: via 
found, flags=2 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20837]: DBG:tm:t_lookup_request: 
start searching: hash=16284, isACK=0 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_via_param: 
found param type 232, <branch> = <z9hG4bK1f688db07e3542d3a>; state=16 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_headers: this 
is the first via 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20837]: DBG:tm:matching_3261: 
RFC3261 transaction matching failed 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: 
checking if host==us: 24==9 &&  [vmopensips1.skycomuk.com] == [127.0.0.1] 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_via: end of 
header reached, state=5 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20838]: DBG:core:receive_msg: After 
parse_msg... 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20837]: DBG:tm:t_lookup_request: no 
transaction found 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: via 
found, flags=2 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20838]: DBG:core:receive_msg: 
preparing to run routing scripts... 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_to_param: 
tag=6392ae5f12 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: 
checking if host==us: 24==11 &&  [vmopensips1.skycomuk.com] == [10.150.0.33] 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: this 
is the first via 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_headers: 
flags=100 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_to: end of 
header reached, state=29 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20835]: DBG:core:receive_msg: After 
parse_msg... 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20838]: 
DBG:maxfwd:is_maxfwd_present: value = 70  
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_to: 
display={"1000"}, ruri={sip:[email protected]:5060} 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: 
checking if host==us: 24==13 &&  [vmopensips1.skycomuk.com] == [212.84.166.33] 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20835]: DBG:core:receive_msg: 
preparing to run routing scripts... 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_headers: 
flags=8 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: 
checking if host==us: 24==9 &&  [vmopensips1.skycomuk.com] == [127.0.0.1] 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20835]: DBG:sl:sl_filter_ACK: to 
late to be a local ACK! 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_to: end of 
header reached, state=10 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_headers: 
flags=10000 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: 
flags=100 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_to: 
display={"1001"}, ruri={sip:[email protected]:5060} 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: 
checking if host==us: 24==11 &&  [vmopensips1.skycomuk.com] == [10.150.0.33] 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20836]: DBG:core:get_hdr_field: 
content_length=595 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20835]: 
DBG:maxfwd:is_maxfwd_present: value = 70  
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20838]: DBG:core:get_hdr_field: <To> 
[49]; uri=[sip:[email protected]:5060]  
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20836]: DBG:core:get_hdr_field: 
found end of header 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: 
flags=8 
 ]   7 09:22:16 vmopensips1 /sbin/opensips[20838]: DBG:core:get_hdr_field: to 
body ["1001" <sip:[email protected]:5060>
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: 
checking if host==us: 24==13 &&  [vmopensips1.skycomuk.com] == [212.84.166.33] 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20836]: DBG:auth:pre_auth: 
credentials with given realm not found 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_to_param: 
tag=c97b4d1cb1f3d0da549e06a8d482ef63.5f56 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20838]: DBG:uri:has_totag: no totag 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20836]: 
DBG:auth:reserve_nonce_index: second= 6, sec_monit= -1,  index= 1 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_to: end of 
header reached, state=29 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_headers: 
flags=78 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: 
checking if host==us: 24==9 &&  [vmopensips1.skycomuk.com] == [127.0.0.1] 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20836]: DBG:auth:build_auth_hf: 
nonce index= 1 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_to: 
display={"1001"}, ruri={sip:[email protected]:5060} 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20838]: DBG:core:get_hdr_field: cseq 
<CSeq>: <6436> <INVITE> 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
 '   7 09:22:16 vmopensips1 /sbin/opensips[20836]: DBG:auth:build_auth_hf: 
'Proxy-Authenticate: Digest realm="vmopensips1.skycomuk.com", 
nonce="4d26db6600000001d69ce33126031746bdf4735e3f0f922d"
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: <To> 
[91]; uri=[sip:[email protected]:5060]  
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20838]: DBG:tm:t_lookup_request: 
start searching: hash=16284, isACK=0 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: 
checking if host==us: 24==11 &&  [vmopensips1.skycomuk.com] == [10.150.0.33] 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_headers: 
flags=ffffffffffffffff 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: to 
body ["1001" <sip:[email protected]:5060>] 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20838]: DBG:tm:matching_3261: 
RFC3261 transaction matching failed 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20836]: DBG:core:check_ip_address: 
params 212.84.170.85, 212.84.170.85, 0 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20835]: DBG:uri:has_totag: totag 
found 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20838]: DBG:tm:t_lookup_request: no 
transaction found 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: 
checking if host==us: 24==13 &&  [vmopensips1.skycomuk.com] == [212.84.166.33] 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20836]: DBG:core:destroy_avp_list: 
destroying list (nil) 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: 
flags=200 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_to_param: 
tag=6392ae5f12 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20836]: DBG:core:receive_msg: 
cleaning up 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: cseq 
<CSeq>: <6436> <ACK> 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_to: end of 
header reached, state=29 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_headers: 
flags=10000 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: 
content_length=0 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_to: 
display={"1000"}, ruri={sip:[email protected]:5060} 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20837]: DBG:core:get_hdr_field: 
content_length=595 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: 
found end of header 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: 
checking if host==us: 24==9 &&  [vmopensips1.skycomuk.com] == [127.0.0.1] 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20837]: DBG:core:get_hdr_field: 
found end of header 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20835]: DBG:rr:find_first_route: No 
Route headers found 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20837]: DBG:auth:pre_auth: 
credentials with given realm not found 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20835]: DBG:rr:loose_route: There is 
no Route HF 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: 
checking if host==us: 24==11 &&  [vmopensips1.skycomuk.com] == [10.150.0.33] 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20837]: 
DBG:auth:reserve_nonce_index: second= 8, sec_monit= -1,  index= 2 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: 
flags=78 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20837]: DBG:auth:build_auth_hf: 
nonce index= 2 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20835]: DBG:tm:t_lookup_request: 
start searching: hash=16284, isACK=1 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: 
checking if host==us: 24==13 &&  [vmopensips1.skycomuk.com] == [212.84.166.33] 
 '   7 09:22:19 vmopensips1 /sbin/opensips[20837]: DBG:auth:build_auth_hf: 
'Proxy-Authenticate: Digest realm="vmopensips1.skycomuk.com", 
nonce="4d26db6900000002df907eceab9018f0d8b6f41664c24279"
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20835]: DBG:tm:matching_3261: 
RFC3261 transaction matching failed 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_headers: 
flags=ffffffffffffffff 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20835]: DBG:tm:t_lookup_request: no 
transaction found 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: 
checking if host==us: 24==9 &&  [vmopensips1.skycomuk.com] == [127.0.0.1] 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20837]: DBG:core:check_ip_address: 
params 212.84.170.85, 212.84.170.85, 0 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20835]: DBG:core:destroy_avp_list: 
destroying list (nil) 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20837]: DBG:core:destroy_avp_list: 
destroying list (nil) 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20835]: DBG:core:receive_msg: 
cleaning up 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: 
checking if host==us: 24==11 &&  [vmopensips1.skycomuk.com] == [10.150.0.33] 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20837]: DBG:core:receive_msg: 
cleaning up 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: 
checking if host==us: 24==13 &&  [vmopensips1.skycomuk.com] == [212.84.166.33] 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: 
checking if port 5060 matches port 5060 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_headers: 
flags=10000 
Jan  7 09:22:20 vmopensips1 /sbin/opensips[20838]: DBG:core:get_hdr_field: 
content_length=595 
Jan  7 09:22:20 vmopensips1 /sbin/opensips[20838]: DBG:core:get_hdr_field: 
found end of header 
Jan  7 09:22:20 vmopensips1 /sbin/opensips[20838]: DBG:auth:pre_auth: 
credentials with given realm not found 
Jan  7 09:22:20 vmopensips1 /sbin/opensips[20838]: 
DBG:auth:reserve_nonce_index: second= 10, sec_monit= -1,  index= 3 
Jan  7 09:22:20 vmopensips1 /sbin/opensips[20838]: DBG:auth:build_auth_hf: 
nonce index= 3 
 '   7 09:22:20 vmopensips1 /sbin/opensips[20838]: DBG:auth:build_auth_hf: 
'Proxy-Authenticate: Digest realm="vmopensips1.skycomuk.com", 
nonce="4d26db6a0000000330a51f25bde49628253cc14e3458c505"
Jan  7 09:22:20 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_headers: 
flags=ffffffffffffffff 
Jan  7 09:22:20 vmopensips1 /sbin/opensips[20838]: DBG:core:check_ip_address: 
params 212.84.170.85, 212.84.170.85, 0 
Jan  7 09:22:20 vmopensips1 /sbin/opensips[20838]: DBG:core:destroy_avp_list: 
destroying list (nil) 
Jan  7 09:22:20 vmopensips1 /sbin/opensips[20838]: DBG:core:receive_msg: 
cleaning up 
_______________________________________________
Users mailing list
[email protected]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users

Reply via email to