Hi,Klaus
The following is the output of openser.....
It seems that minsip send a correct REGISTER.....
Jan 11 17:37:20 [11282] DBG:core:tls_update_fd: New fd is 10
Jan 11 17:37:20 [11282] DBG:core:tls_update_fd: New fd is 10
Jan 11 17:37:20 [11282] DBG:core:_tls_read: 377 bytes read
Jan 11 17:37:20 [11282] DBG:core:tcp_read_req: content-length= 0
Jan 11 17:37:20 [11282] DBG:core:parse_msg: SIP Request:
Jan 11 17:37:20 [11282] DBG:core:parse_msg: method: <REGISTER>
Jan 11 17:37:20 [11282] DBG:core:parse_msg: uri: <sip:10.11.57.197>
Jan 11 17:37:20 [11282] DBG:core:parse_msg: version: <SIP/2.0>
Jan 11 17:37:20 [11282] DBG:core:parse_headers: flags=2
Jan 11 17:37:20 [11282] DBG:core:parse_to: end of header reached, state=10
Jan 11 17:37:20 [11282] DBG:core:parse_to: display={}, ruri={
sip:888@10.11.57.197}
Jan 11 17:37:20 [11282] DBG:core:get_hdr_field: <To> [24]; uri=[
sip:888@10.11.57.197]
Jan 11 17:37:20 [11282] DBG:core:get_hdr_field: to body [<
sip:888@10.11.57.197>
]
Jan 11 17:37:20 [11282] DBG:core:get_hdr_field: cseq <CSeq>: <901>
<REGISTER>
Jan 11 17:37:20 [11282] DBG:core:parse_via_param: found param type 235,
<rport> = <n/a>; state=6
Jan 11 17:37:20 [11282] DBG:core:parse_via_param: found param type 232,
<branch> = <z9hG4bK26500>; state=16
Jan 11 17:37:20 [11282] DBG:core:parse_via: end of header reached, state=5
Jan 11 17:37:20 [11282] DBG:core:parse_headers: via found, flags=2
Jan 11 17:37:20 [11282] DBG:core:parse_headers: this is the first via
Jan 11 17:37:20 [11282] DBG:core:receive_msg: After parse_msg...
Jan 11 17:37:20 [11282] DBG:core:receive_msg: preparing to run routing
scripts...
message buffer: REGISTER sip:10.11.57.197 SIP/2.0
Route: <sip:10.11.57.197:5061;transport=TLS;lr>
From: <sip:888@10.11.57.197>
To: <sip:888@10.11.57.197>
Call-ID: 6334(a)10.11.57.192
CSeq: 901 REGISTER
Max-Forwards: 70
Contact: <sip:888@10.11.57.192:5061;transport=TLS>;expires=1000
User-Agent: Minisip
Via: SIP/2.0/TLS 10.11.57.192:5061;rport;branch=z9hG4bK26500
Content-Length: 0
Jan 11 17:37:20 [11282] DBG:maxfwd:is_maxfwd_present: value = 70
Jan 11 17:37:20 [11282] DBG:core:parse_headers: flags=200
Jan 11 17:37:20 [11282] DBG:rr:is_preloaded: is_preloaded: Yes
Jan 11 17:37:20 [11282] DBG:core:grep_sock_info: checking if host==us:
12==12 && [10.11.57.197] == [10.11.57.197]
Jan 11 17:37:20 [11282] DBG:core:grep_sock_info: checking if port 5061
matches port 5061
Jan 11 17:37:20 [11282] DBG:rr:after_loose: Topmost route URI: 'sip:
10.11.57.197:5061;transport=TLS;lr' is me
Jan 11 17:37:20 [11282] DBG:core:parse_headers: flags=200
Jan 11 17:37:20 [11282] DBG:core:get_hdr_field: content_length=0
Jan 11 17:37:20 [11282] DBG:core:get_hdr_field: found end of header
Jan 11 17:37:20 [11282] DBG:rr:find_next_route: No next Route HF found
Jan 11 17:37:20 [11282] DBG:rr:after_loose: No next URI found
Jan 11 17:37:20 [11282] DBG:core:grep_sock_info: checking if host==us:
12==12 && [10.11.57.197] == [10.11.57.197]
Jan 11 17:37:20 [11282] DBG:core:grep_sock_info: checking if port 5061
matches port 5060
Jan 11 17:37:20 [11282] DBG:core:check_self: host != me
Jan 11 17:37:20 [11282] DBG:core:parse_headers: flags=ffffffffffffffff
Jan 11 17:37:20 [11282] DBG:tm:t_newtran: T on entrance=0xffffffff
Jan 11 17:37:20 [11282] DBG:core:parse_headers: flags=ffffffffffffffff
Jan 11 17:37:20 [11282] DBG:core:parse_headers: flags=78
Jan 11 17:37:20 [11282] DBG:tm:t_lookup_request: start searching:
hash=58073, isACK=0
Jan 11 17:37:20 [11282] DBG:tm:matching_3261: RFC3261 transaction matching
failed
Jan 11 17:37:20 [11282] DBG:tm:t_lookup_request: no transaction found
Jan 11 17:37:20 [11282] DBG:core:mk_proxy: doing DNS lookup...
Jan 11 17:37:20 [11282] ERROR:tm:update_uac_dst: failed to fwd to af 2,
proto 1 (no corresponding listening socket)
Jan 11 17:37:20 [11282] ERROR:tm:t_forward_nonack: failure to add branches
Jan 11 17:37:20 [11282] DBG:tm:t_relay_to: t_forward_nonack returned error
Jan 11 17:37:20 [11282] DBG:core:parse_headers: flags=ffffffffffffffff
Jan 11 17:37:20 [11282] DBG:core:check_via_address: params 10.11.57.192,
10.11.57.192, 0
Jan 11 17:37:20 [11282] DBG:core:_shm_resize: resize(0) called
Jan 11 17:37:20 [11282] DBG:tm:cleanup_uac_timers: RETR/FR timers reset
Jan 11 17:37:20 [11282] DBG:tm:insert_timer_unsafe: [2]: 0xb5d06518 (20)
Jan 11 17:37:20 [11282] DBG:core:tcp_send: tcp connection found
(0xb5ce24f8), acquiring fd
Jan 11 17:37:20 [11282] DBG:core:tcp_send: c= 0xb5ce24f8, n=8
Jan 11 17:37:20 [11286] DBG:core:handle_ser_child: read response= b5ce24f8,
1, fd -1 from 2 (11282)
Jan 11 17:37:20 [11282] DBG:core:tcp_send: after receive_fd: c= 0xb5ce24f8
n=4 fd=11
Jan 11 17:37:20 [11282] DBG:core:tcp_send: sending...
Jan 11 17:37:20 [11282] DBG:core:tls_update_fd: New fd is 11
Jan 11 17:37:20 [11282] DBG:core:tls_write: write was successful (325 bytes)
Jan 11 17:37:20 [11282] DBG:core:tcp_send: after write: c= 0xb5ce24f8 n=325
fd=11
Jan 11 17:37:20 [11282] DBG:core:tcp_send: buf=
SIP/2.0 500 Server error occurred (7/TM)
From: <sip:888@10.11.57.197>
To: <sip:888@10.11.57.197>;tag=6de70244a9439b1a95183831634130e2-feb6
Call-ID: 6334(a)10.11.57.192
CSeq: 901 REGISTER
Via: SIP/2.0/TLS 10.11.57.192:5061;rport=1613;branch=z9hG4bK26500
Server: OpenSER (1.3.0-pre1-tls (i386/linux))
Content-Length: 0
On 1/11/08, Klaus Darilion <klaus.mailinglists(a)pernau.at> wrote:
you have to load the xlog module
fengbin schrieb:
Dear,Klaus,
There is an error of " <xlog> not found" while I put that phrase
On 1/11/08, *Klaus Darilion* <klaus.mailinglists(a)pernau.at
<mailto:klaus.mailinglists@pernau.at>> wrote:
Hi Fengbin!
Cc'ed to the openser list ...
fengbin schrieb:
Hi,Klaus,
How to use NULL cipher? Only setting in Openser is ok? I mean do
I need
to set NULL cipher at client site?
Usually the NULL cipher is not enabled (for security reasons). You
have
to enable it on both sides, the server and
the client. But if you
use
the following approach you do not need it.
And where to put
xlog("L_ERR","message buffer: $mb"); anywhere in
openser.cfg ?
Put it just in the beginning of the route block.
regards
klaus
THX
BR
On 1/11/08, *Klaus Darilion* < klaus.mailinglists(a)pernau.at
<mailto:klaus.mailinglists@pernau.at>
<mailto: klaus.mailinglists(a)pernau.at
<mailto:klaus.mailinglists@pernau.at>>> wrote:
The capture file is not helpful, as it is encrypted. You
could use NULL
> cipher to have plaintext inside the TLS connection to inspect
the
incoming SIP message, or add xlog("L_ERR","message buffer:
$mb"); to see
> the whole incoming SIP request.
>
> regards
> klaus
>
> fengbin schrieb:
> > Hi,Klaus
> > Thank you for your reply.
> > The enclosed is the config file ,the pcap between client
and
server and
> the log on the openser 's console.
> Could you please take a look at them for me?
>
> THX
> BR
>
>
> On 1/10/08, *Klaus Darilion* <
klaus.mailinglists(a)pernau.at
<mailto:klaus.mailinglists@pernau.at>
<mailto:klaus.mailinglists@pernau.at
<mailto:klaus.mailinglists@pernau.at>>
> <mailto:
klaus.mailinglists(a)pernau.at
<mailto:klaus.mailinglists@pernau.at>
<mailto:klaus.mailinglists@pernau.at
<mailto:klaus.mailinglists@pernau.at>> >> wrote:
>
> Can you show us the REGISTER request? (both, port 5060
and
port 5061).
>
> Further show use your openser config
>
> regards
> klaus
>
> fengbin schrieb:
> >
> > Hi,all
> > I met a strange problem while I am testing TLS
connection
between
> minisip and openser.
> The following is my openser.cfg (part of that)
>
> .........
> fork=no
> log_stderror=yes
>
> # Uncomment this to prevent the blacklisting of
temporary not
> > available destinations
> > #disable_dns_blacklist=yes
> >
> > # # Uncomment this to prevent the IPv6 lookup
after
v4
dns lookup
> > failures
> > #dns_try_ipv6=no
> >
> > # uncomment the following lines for TLS support
> > disable_tls = 0
> > listen = tls: 10.11.57.197:5060
<http://10.11.57.197:5060/>
<
http://10.11.57.197:5060
<http://10.11.57.197:5060/>>
<http://10.11.57.197:5060
<http://10.11.57.197:5060/>>
<
http://10.11.57.197:5060 <http://10.11.57.197:5060/
> >
> >
> > tls_verify_client = 1
> > tls_method = TLSv1
> > tls_certificate =
"/usr/local/etc/openser//tls/user/user-
> cert.pem"
> > tls_private_key =
> "/usr/local/etc/openser//tls/user/user- privkey.pem"
> > tls_ca_list =
"/usr/local/etc/openser//tls/user/user-
calist.pem"
> >
tls_ciphers_list="NULL-SHA:NULL-MD5:AES256-SHA:AES128-SHA"
> > ......
> >
> > When I set "tls: 10.11.57.197:5061
<http://10.11.57.197:5061/>
<
http://10.11.57.197:5061
<http://10.11.57.197:5061/>>
<http://10.11.57.197:5061
<http://10.11.57.197:5061/>> <
> >
http://10.11.57.197:5061
<http://10.11.57.197:5061/>>"
the
> > > registration never
succeed. But if I set it to 5060
the
> registration
> > > over TLS is OK.
> > > I compared the log of two scenarioes and found the
TLS
session
> both are
> > OK,but the difference is that:
> > when the port is 5061 there is an error of
forwarding. but
the
>
forwarding is because openser think it's not the
destination of
> > the registration request. See bellow:
> >
> > Jan 10 16:46:56 [9199] DBG:rr:after_loose: No
next
URI
found
> Jan 10 16:46:56 [9199]
DBG:core:grep_sock_info:
checking if
> > host==us: 12==12 && [ 10.11.57.197
<http://10.11.57.197/>
<http://10.11.57.197
<http://10.11.57.197/>> <
http://10.11.57.197
<http://10.11.57.197/>>
> <http://10.11.57.197
<http://10.11.57.197/> <
http://10.11.57.197
<http://10.11.57.197/>>>] ==
> > [10.11.57.197
<http://10.11.57.197/> <
http://10.11.57.197
<http://10.11.57.197/>>
<
http://10.11.57.197
<http://10.11.57.197/>> <
http://10.11.57.197
<http://10.11.57.197/>>]
>
Jan 10 16:46:56 [9199] DBG:core:grep_sock_info:
checking if port
> > 5061 matches port 5060
> > Jan 10 16:46:56 [9199] DBG:core:check_self:
host !=
me
> > Jan 10 16:46:56 [9199]
DBG:core:parse_headers:
> flags=ffffffffffffffff
> > Jan 10 16:46:56 [9199] DBG:tm:t_newtran: T on
> entrance=0xffffffff
> > Jan 10 16:46:56 [9199] DBG:core:parse_headers:
> flags=ffffffffffffffff
> > Jan 10 16:46:56 [9199] DBG:core:parse_headers:
flags=78
> > Jan 10 16:46:56 [9199]
DBG:tm:t_lookup_request:
start
searching:
> > hash=58073, isACK=0
> > Jan 10 16:46:56 [9199] DBG:tm:matching_3261:
RFC3261
> transaction
> > > matching failed
> > > Jan 10 16:46:56 [9199] DBG:tm:t_lookup_request:
no
> > transaction found
> > > Jan 10 16:46:56 [9199] DBG:core:mk_proxy: doing
DNS
lookup...
> > Jan 10 16:46:56 [9199] ERROR:tm:update_uac_dst:
failed
> to fwd
> > to af
> > > 2, proto 1 (no corresponding listening socket)
> > > Jan 10 16:46:56 [9199]
ERROR:tm:t_forward_nonack:
failure to add
> > branches
> >
> >
> >
> > With comparition to that when the port is set to
5060 the
trace is :
> >
> > Jan 10 17:07:59 [9410] DBG:rr:find_next_route:
No
next
Route
> HF found
> > Jan 10 17:07:59 [9410] DBG:rr:after_loose: No
next
URI
found
> Jan 10 17:07:59 [9410]
DBG:core:grep_sock_info:
checking if
> > host==us: 12==12 && [ 10.11.57.197
<http://10.11.57.197/>
<http://10.11.57.197
<http://10.11.57.197/>> <
http://10.11.57.197
<http://10.11.57.197/>>
> <http://10.11.57.197
<http://10.11.57.197/>>] ==
> > [ 10.11.57.197 <http://10.11.57.197/> <
http://10.11.57.197 <http://10.11.57.197/>>
<http://10.11.57.197
<http://10.11.57.197/>> <
http://10.11.57.197
<http://10.11.57.197/>>]
>
Jan 10 17:07:59 [9410] DBG:core:grep_sock_info:
checking if port
> > 5060 matches port 5060
> Jan 10 17:07:59 [9410]
DBG:core:grep_sock_info:
checking if
> > host==us: 12==12 && [10.11.57.197
<http://10.11.57.197/>
<
http://10.11.57.197
<http://10.11.57.197/>> <
http://10.11.57.197
<http://10.11.57.197/>>
> <http://10.11.57.197
<http://10.11.57.197/>>] ==
> > [ 10.11.57.197 <http://10.11.57.197/> <
http://10.11.57.197 <http://10.11.57.197/>> <
http://10.11.57.197
<http://10.11.57.197/>> <
http://10.11.57.197
<http://10.11.57.197/>>]
> > > Jan 10 17:07:59 [9410] DBG:core:grep_sock_info:
> checking if port
> > > 5060 matches port 5060
> > > Jan 10 17:07:59 [9410] DBG:core:parse_headers:
> > flags=ffffffffffffffff
> > > Jan 10 17:07:59 [9410] DBG:core:parse_headers:
> flags=8000000
> > > Jan 10 17:07:59 [9410] DBG:core:parse_headers:
> > flags=ffffffffffffffff
> > > Jan 10 17:07:59 [9410]
DBG:registrar:build_contact:
created
> Contact
> > HF: Contact:
> <sip:888@10.11.57.192:5061;transport=TLS>;expires=1000
> >
> >
> >
> > And there is no fwd needed then.So the error didnt
occur.
> > >
> > > Its a little bit strange that when I set the port
to
5061,why did
> openser check the port 5060?????
> Can anyone help me to figure it out?
> THX
> BR
>
>
>
>
>
>
>
>
>
>
>
>
> --
> Fengbin
>
>
>
------------------------------------------------------------------------
> >
> > _______________________________________________
> > Users mailing list
> > Users(a)lists.openser.org
<mailto:Users@lists.openser.org> <mailto:Users@lists.openser.org
<mailto:Users@lists.openser.org>>
<mailto: Users(a)lists.openser.org
<mailto:Users@lists.openser.org> <mailto: Users(a)lists.openser.org
<mailto:Users@lists.openser.org>>>
> > >
http://lists.openser.org/cgi-bin/mailman/listinfo/users