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