Thanks. I have done that but the only debug messages I get is the one I
added myself just after the 'route{' line at the very start.
Is the following line from the logs significant? I dont have multidomain
support enabled.
Jan 18 14:55:29 [8644] DBG:auth:pre_auth: credentials with given realm
not found
Bogdan-Andrei Iancu wrote:
Hi
try to place a log as:
xlog("before record routing\n");
before the line with :
# record routing
another one like :
xlog("doing lookup\n");
before:
#do lookup with method filtering
and one in the beginning of route[1]:
xlog("sending request $rm out \n");
Check which logs do appear.
Regards,
Bogdan
Gareth Blades wrote:
I installed a caching nameserver but it made no difference.
I then switched logging from syslog to stderr and thats much better
and the phone can register fine.
I have attached the debug from when I tried making the call between
lines. If there is nothing usefull there then can you let me know
where I could put some additional loggin in the config file in order
to help.
Thanks
Bogdan-Andrei Iancu wrote:
Hi Gareth,
Gareth Blades wrote:
I am having a problem with running opensips in debug level 6. When
opensips is set to this I am finding that it takes a long time to
respond to register requests (over 5 seconds compared to a fraction
of a second) which means that my phone times out when trying to
register so I cannot then debug trying to send calls through.
woow...that is really strange.....never encountered something like
that....do you log to stderror(console) or to syslog ?
Any ideas?
DNS timeouts are a common cause for these sort of pauses. Are there
any specific DNS setup requirements that opensips has that I might
have missing?
see the DNS related params:
http://www.opensips.org/Resources/DocsCoreFcn#toc41
Also, better use DNS cache app between your opensips and the outer
world.
So, your missing INVITE (not being sent out) are because of opensips
blocking in some DNS query ?
Regards,
Bogdan
Thanks
Gareth
Bogdan-Andrei Iancu wrote:
Hi Gareth,
On a first look, the script looks ok, but as a general way to
debug/troubleshoot your script, place xlog()'s in your script, in
different points, to see if the script execution gets to that point.
Regarding the 408 - take care your script does not have NAT
support, so it may not work if your client is behind a NAT.
Regards,
Bogdan
Gareth Blades wrote:
Thanks I will need to get back to you on Monday.
The phone on my desk has just started not being able to register.
Its showing registration status 408 which is no response.
I can see the opensips server receiving the the registration and
issuing a 401 unauthorised but I dont think this is getting back
through the firewall.
I will get some static forwarding added to the firewall to avoid
this sort of issue complicaing investigating the other problem.
In the meantime I have attached my config file.
Bogdan-Andrei Iancu wrote:
Hi Gareth,
looking at the logs, it seams that your script processing (for
the INVITE) never get to a t_relay() point - place some xlog()
prints in your script to see where the INVITE processing is going
through.
Regards,
Bogdan
Gareth Blades wrote:
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
------------------------------------------------------------------------
_______________________________________________
Users mailing list
[email protected]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
U 212.84.178.71:5060 -> 212.84.166.33:5060
INVITE sip:[email protected]:5060 SIP/2.0.
Via: SIP/2.0/UDP 212.84.178.71:5060;branch=z9hG4bK73658aefde39bee35.
Max-Forwards: 70.
From: "1000" <sip:[email protected]:5060>;tag=da5d758c2a.
To: "1001" <sip:[email protected]:5060>.
Call-ID: 42aba56e029d925e.
CSeq: 31079 INVITE.
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK,
SUBSCRIBE, INFO.
Allow-Events: talk, hold, conference, LocalModeStatus.
Contact: "1000"
<sip:[email protected]:5060;transport=udp>;+sip.instance="<urn:uuid:00000000-0000-1000-8000-00085D23801E>".
Supported: gruu, path, timer, 100rel, replaces.
User-Agent: Aastra 55i/2.5.2.1010.
Content-Type: application/sdp.
Content-Length: 595.
.
v=0.
o=MxSIP 0 0 IN IP4 192.168.2.11.
s=SIP Call.
c=IN IP4 212.84.178.71.
t=0 0.
m=audio 3000 RTP/AVP 0 18 106 107 113 110 111 112 98 97 115 96 9 8 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:18 G729/8000.
a=rtpmap:106 BV16/8000.
a=rtpmap:107 BV32/16000.
a=rtpmap:113 L16/16000.
a=rtpmap:110 PCMU/16000.
a=rtpmap:111 PCMA/16000.
a=rtpmap:112 L16/8000.
a=rtpmap:98 G726-16/8000.
a=rtpmap:97 G726-24/8000.
a=rtpmap:115 G726-32/8000.
a=rtpmap:96 G726-40/8000.
a=rtpmap:9 G722/8000.
a=rtpmap:8 PCMA/8000.
a=rtpmap:101 telephone-event/8000.
a=silenceSupp:on - - - -.
a=fmtp:101 0-15.
a=ptime:30.
a=sendrecv.
Jan 18 15:05:30 [9057] DBG:core:parse_msg: SIP Request:
Jan 18 15:05:30 [9057] DBG:core:parse_msg: method: <INVITE>
Jan 18 15:05:30 [9057] DBG:core:parse_msg: uri:
<sip:[email protected]:5060>
Jan 18 15:05:30 [9057] DBG:core:parse_msg: version: <SIP/2.0>
Jan 18 15:05:30 [9057] DBG:core:parse_headers: flags=2
Jan 18 15:05:30 [9057] DBG:core:parse_via_param: found param type 232, <branch>
= <z9hG4bK73658aefde39bee35>; state=16
Jan 18 15:05:30 [9057] DBG:core:parse_via: end of header reached, state=5
Jan 18 15:05:30 [9057] DBG:core:parse_headers: via found, flags=2
Jan 18 15:05:30 [9057] DBG:core:parse_headers: this is the first via
Jan 18 15:05:30 [9057] DBG:core:receive_msg: After parse_msg...
Jan 18 15:05:30 [9057] DBG:core:receive_msg: preparing to run routing scripts...
=========== something happened - start of route
Jan 18 15:05:30 [9057] DBG:core:parse_headers: flags=100
Jan 18 15:05:30 [9057] DBG:maxfwd:is_maxfwd_present: value = 70
Jan 18 15:05:30 [9057] DBG:core:parse_headers: flags=8
Jan 18 15:05:30 [9057] DBG:core:parse_to: end of header reached, state=10
Jan 18 15:05:30 [9057] DBG:core:parse_to: display={"1001"},
ruri={sip:[email protected]:5060}
Jan 18 15:05:30 [9057] DBG:core:get_hdr_field: <To> [49];
uri=[sip:[email protected]:5060]
Jan 18 15:05:30 [9057] DBG:core:get_hdr_field: to body ["1001"
<sip:[email protected]:5060>
]
Jan 18 15:05:30 [9057] DBG:uri:has_totag: no totag
Jan 18 15:05:30 [9057] DBG:core:parse_headers: flags=78
Jan 18 15:05:30 [9057] DBG:core:get_hdr_field: cseq <CSeq>: <31079> <INVITE>
Jan 18 15:05:30 [9057] DBG:tm:t_lookup_request: start searching: hash=16191,
isACK=0
Jan 18 15:05:30 [9057] DBG:tm:matching_3261: RFC3261 transaction matching failed
Jan 18 15:05:30 [9057] DBG:tm:t_lookup_request: no transaction found
Jan 18 15:05:30 [9057] DBG:core:parse_to_param: tag=da5d758c2a
Jan 18 15:05:30 [9057] DBG:core:parse_to: end of header reached, state=29
Jan 18 15:05:30 [9057] DBG:core:parse_to: display={"1000"},
ruri={sip:[email protected]:5060}
Jan 18 15:05:30 [9057] DBG:core:grep_sock_info: checking if host==us: 24==13 &&
[vmopensips1.skycomuk.com] == [212.84.166.33]
Jan 18 15:05:30 [9057] DBG:core:grep_sock_info: checking if port 5060 matches
port 5060
Jan 18 15:05:30 [9057] DBG:core:grep_sock_info: checking if host==us: 24==13 &&
[vmopensips1.skycomuk.com] == [212.84.166.33]
Jan 18 15:05:30 [9057] DBG:core:grep_sock_info: checking if port 5060 matches
port 5060
Jan 18 15:05:30 [9057] DBG:core:parse_headers: flags=10000
Jan 18 15:05:30 [9057] DBG:core:get_hdr_field: content_length=595
Jan 18 15:05:30 [9057] DBG:core:get_hdr_field: found end of header
Jan 18 15:05:30 [9057] DBG:auth:pre_auth: credentials with given realm not found
Jan 18 15:05:30 [9057] DBG:auth:reserve_nonce_index: second= 20, sec_monit= -1,
index= 1
Jan 18 15:05:30 [9057] DBG:auth:build_auth_hf: nonce index= 1
Jan 18 15:05:30 [9057] DBG:auth:build_auth_hf: 'Proxy-Authenticate: Digest
realm="vmopensips1.skycomuk.com",
nonce="4d35ac5800000001f3bd3700f67bd497cadc69bef83fd0cb"
'
Jan 18 15:05:30 [9057] DBG:core:parse_headers: flags=ffffffffffffffff
Jan 18 15:05:30 [9057] DBG:core:check_ip_address: params 212.84.178.71,
212.84.178.71, 0
Jan 18 15:05:30 [9057] DBG:core:destroy_avp_list: destroying list (nil)
Jan 18 15:05:30 [9057] DBG:core:receive_msg: cleaning up
U 212.84.166.33:5060 -> 212.84.178.71:5060
SIP/2.0 407 Proxy Authentication Required.
Via: SIP/2.0/UDP 212.84.178.71:5060;branch=z9hG4bK73658aefde39bee35.
From: "1000" <sip:[email protected]:5060>;tag=da5d758c2a.
To: "1001"
<sip:[email protected]:5060>;tag=b3addd350d7d55a695048985db4db659.c74d.
Call-ID: 42aba56e029d925e.
CSeq: 31079 INVITE.
Proxy-Authenticate: Digest realm="vmopensips1.skycomuk.com",
nonce="4d35ac5800000001f3bd3700f67bd497cadc69bef83fd0cb".
Server: OpenSIPS (1.6.4-notls (x86_64/linux)).
Content-Length: 0.
.
U 212.84.178.71:5060 -> 212.84.166.33:5060
ACK sip:[email protected]:5060 SIP/2.0.
Via: SIP/2.0/UDP 212.84.178.71:5060;branch=z9hG4bK73658aefde39bee35.
Max-Forwards: 70.
From: "1000" <sip:[email protected]:5060>;tag=da5d758c2a.
To: "1001"
<sip:[email protected]:5060>;tag=b3addd350d7d55a695048985db4db659.c74d.
Call-ID: 42aba56e029d925e.
CSeq: 31079 ACK.
User-Agent: Aastra 55i/2.5.2.1010.
Content-Length: 0.
.
Jan 18 15:05:30 [9057] DBG:core:parse_msg: SIP Request:
Jan 18 15:05:30 [9057] DBG:core:parse_msg: method: <ACK>
Jan 18 15:05:30 [9057] DBG:core:parse_msg: uri:
<sip:[email protected]:5060>
Jan 18 15:05:30 [9057] DBG:core:parse_msg: version: <SIP/2.0>
Jan 18 15:05:30 [9057] DBG:core:parse_headers: flags=2
Jan 18 15:05:30 [9057] DBG:core:parse_via_param: found param type 232, <branch>
= <z9hG4bK73658aefde39bee35>; state=16
Jan 18 15:05:30 [9057] DBG:core:parse_via: end of header reached, state=5
Jan 18 15:05:30 [9057] DBG:core:parse_headers: via found, flags=2
Jan 18 15:05:30 [9057] DBG:core:parse_headers: this is the first via
Jan 18 15:05:30 [9057] DBG:core:receive_msg: After parse_msg...
Jan 18 15:05:30 [9057] DBG:core:receive_msg: preparing to run routing scripts...
Jan 18 15:05:30 [9057] DBG:core:parse_headers: flags=8
Jan 18 15:05:30 [9057] DBG:core:parse_to_param:
tag=b3addd350d7d55a695048985db4db659.c74d
Jan 18 15:05:30 [9057] DBG:core:parse_to: end of header reached, state=29
Jan 18 15:05:30 [9057] DBG:core:parse_to: display={"1001"},
ruri={sip:[email protected]:5060}
Jan 18 15:05:30 [9057] DBG:core:get_hdr_field: <To> [91];
uri=[sip:[email protected]:5060]
Jan 18 15:05:30 [9057] DBG:core:get_hdr_field: to body ["1001"
<sip:[email protected]:5060>]
Jan 18 15:05:30 [9057] DBG:sl:sl_filter_ACK: local ACK found -> dropping it!
Jan 18 15:05:30 [9057] DBG:core:destroy_avp_list: destroying list (nil)
Jan 18 15:05:30 [9057] DBG:core:receive_msg: cleaning up
U 212.84.178.71:5060 -> 212.84.166.33:5060
INVITE sip:[email protected]:5060 SIP/2.0.
Via: SIP/2.0/UDP 212.84.178.71:5060;branch=z9hG4bKb95352f6f9a6634fd.
Proxy-Authorization: Digest
username="1000",realm="vmopensips1.skycomuk.com",nonce="4d35ac5800000001f3bd3700f67bd497cadc69bef83fd0cb",uri="sip:[email protected]:5060",response="a426010f6ee341153dad82f48f5cec09".
Max-Forwards: 70.
From: "1000" <sip:[email protected]:5060>;tag=da5d758c2a.
To: "1001" <sip:[email protected]:5060>.
Call-ID: 42aba56e029d925e.
CSeq: 31080 INVITE.
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK,
SUBSCRIBE, INFO.
Allow-Events: talk, hold, conference, LocalModeStatus.
Contact: "1000"
<sip:[email protected]:5060;transport=udp>;+sip.instance="<urn:uuid:00000000-0000-1000-8000-00085D23801E>".
Supported: gruu, path, timer, 100rel, replaces.
User-Agent: Aastra 55i/2.5.2.1010.
Content-Type: application/sdp.
Content-Length: 528.
.
v=0.
o=MxSIP 0 0 IN IP4 192.168.2.11.
s=SIP Call.
c=IN IP4 212.84.178.71.
t=0 0.
m=audio 3000 RTP/AVP 0 18 106 107 113 110 111 112 98 97 115 96 9 8 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:18 G729/8000.
a=rtpmap:106 BV16/8000.
a=rtpmap:107 BV32/16000.
a=rtpmap:113 L16/16000.
a=rtpmap:110 PCMU/16000.
a=rtpmap:111 PCMA/16000.
a=rtpmap:112 L16/8000.
a=rtpmap:98 G726-16/8000.
a=rtpmap:97 G726-24/8000.
a=rtpmap:115 G726-32/8000.
a=rtpmap:96 G726-40/8000.
a=rtpmap:9 G722/8000.
a=rtpmap:8 PCMA/8000.
a=rtpmap:101 telephone-event/8000.
U 212.84.178.71:5060 -> 212.84.166.33:5060
INVITE sip:[email protected]:5060 SIP/2.0.
Via: SIP/2.0/UDP 212.84.178.71:5060;branch=z9hG4bKb95352f6f9a6634fd.
Proxy-Authorization: Digest
username="1000",realm="vmopensips1.skycomuk.com",nonce="4d35ac5800000001f3bd3700f67bd497cadc69bef83fd0cb",uri="sip:[email protected]:5060",response="a426010f6ee341153dad82f48f5cec09".
Max-Forwards: 70.
From: "1000" <sip:[email protected]:5060>;tag=da5d758c2a.
To: "1001" <sip:[email protected]:5060>.
Call-ID: 42aba56e029d925e.
CSeq: 31080 INVITE.
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK,
SUBSCRIBE, INFO.
Allow-Events: talk, hold, conference, LocalModeStatus.
Contact: "1000"
<sip:[email protected]:5060;transport=udp>;+sip.instance="<urn:uuid:00000000-0000-1000-8000-00085D23801E>".
Supported: gruu, path, timer, 100rel, replaces.
User-Agent: Aastra 55i/2.5.2.1010.
Content-Type: application/sdp.
Content-Length: 528.
.
v=0.
o=MxSIP 0 0 IN IP4 192.168.2.11.
s=SIP Call.
c=IN IP4 212.84.178.71.
t=0 0.
m=audio 3000 RTP/AVP 0 18 106 107 113 110 111 112 98 97 115 96 9 8 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:18 G729/8000.
a=rtpmap:106 BV16/8000.
a=rtpmap:107 BV32/16000.
a=rtpmap:113 L16/16000.
a=rtpmap:110 PCMU/16000.
a=rtpmap:111 PCMA/16000.
a=rtpmap:112 L16/8000.
a=rtpmap:98 G726-16/8000.
a=rtpmap:97 G726-24/8000.
a=rtpmap:115 G726-32/8000.
a=rtpmap:96 G726-40/8000.
a=rtpmap:9 G722/8000.
a=rtpmap:8 PCMA/8000.
a=rtpmap:101 telephone-event/8000.
U 212.84.178.71:5060 -> 212.84.166.33:5060
INVITE sip:[email protected]:5060 SIP/2.0.
Via: SIP/2.0/UDP 212.84.178.71:5060;branch=z9hG4bKb95352f6f9a6634fd.
Proxy-Authorization: Digest
username="1000",realm="vmopensips1.skycomuk.com",nonce="4d35ac5800000001f3bd3700f67bd497cadc69bef83fd0cb",uri="sip:[email protected]:5060",response="a426010f6ee341153dad82f48f5cec09".
Max-Forwards: 70.
From: "1000" <sip:[email protected]:5060>;tag=da5d758c2a.
To: "1001" <sip:[email protected]:5060>.
Call-ID: 42aba56e029d925e.
CSeq: 31080 INVITE.
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK,
SUBSCRIBE, INFO.
Allow-Events: talk, hold, conference, LocalModeStatus.
Contact: "1000"
<sip:[email protected]:5060;transport=udp>;+sip.instance="<urn:uuid:00000000-0000-1000-8000-00085D23801E>".
Supported: gruu, path, timer, 100rel, replaces.
User-Agent: Aastra 55i/2.5.2.1010.
Content-Type: application/sdp.
Content-Length: 528.
.
v=0.
o=MxSIP 0 0 IN IP4 192.168.2.11.
s=SIP Call.
c=IN IP4 212.84.178.71.
t=0 0.
m=audio 3000 RTP/AVP 0 18 106 107 113 110 111 112 98 97 115 96 9 8 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:18 G729/8000.
a=rtpmap:106 BV16/8000.
a=rtpmap:107 BV32/16000.
a=rtpmap:113 L16/16000.
a=rtpmap:110 PCMU/16000.
a=rtpmap:111 PCMA/16000.
a=rtpmap:112 L16/8000.
a=rtpmap:98 G726-16/8000.
a=rtpmap:97 G726-24/8000.
a=rtpmap:115 G726-32/8000.
a=rtpmap:96 G726-40/8000.
a=rtpmap:9 G722/8000.
a=rtpmap:8 PCMA/8000.
a=rtpmap:101 telephone-event/8000.
U 212.84.178.71:5060 -> 212.84.166.33:5060
INVITE sip:[email protected]:5060 SIP/2.0.
Via: SIP/2.0/UDP 212.84.178.71:5060;branch=z9hG4bKb95352f6f9a6634fd.
Proxy-Authorization: Digest
username="1000",realm="vmopensips1.skycomuk.com",nonce="4d35ac5800000001f3bd3700f67bd497cadc69bef83fd0cb",uri="sip:[email protected]:5060",response="a426010f6ee341153dad82f48f5cec09".
Max-Forwards: 70.
From: "1000" <sip:[email protected]:5060>;tag=da5d758c2a.
To: "1001" <sip:[email protected]:5060>.
Call-ID: 42aba56e029d925e.
CSeq: 31080 INVITE.
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK,
SUBSCRIBE, INFO.
Allow-Events: talk, hold, conference, LocalModeStatus.
Contact: "1000"
<sip:[email protected]:5060;transport=udp>;+sip.instance="<urn:uuid:00000000-0000-1000-8000-00085D23801E>".
Supported: gruu, path, timer, 100rel, replaces.
User-Agent: Aastra 55i/2.5.2.1010.
Content-Type: application/sdp.
Content-Length: 528.
.
v=0.
o=MxSIP 0 0 IN IP4 192.168.2.11.
s=SIP Call.
c=IN IP4 212.84.178.71.
t=0 0.
m=audio 3000 RTP/AVP 0 18 106 107 113 110 111 112 98 97 115 96 9 8 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:18 G729/8000.
a=rtpmap:106 BV16/8000.
a=rtpmap:107 BV32/16000.
a=rtpmap:113 L16/16000.
a=rtpmap:110 PCMU/16000.
a=rtpmap:111 PCMA/16000.
a=rtpmap:112 L16/8000.
a=rtpmap:98 G726-16/8000.
a=rtpmap:97 G726-24/8000.
a=rtpmap:115 G726-32/8000.
a=rtpmap:96 G726-40/8000.
a=rtpmap:9 G722/8000.
a=rtpmap:8 PCMA/8000.
a=rtpmap:101 telephone-event/8000.
_______________________________________________
Users mailing list
[email protected]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
