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@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: 0Jan 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@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
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@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@pernau.at
> <mailto:klaus.mailinglists@pernau.at>
> > <mailto: klaus.mailinglists@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@pernau.at <mailto:klaus.mailinglists@pernau.at >
> > <mailto:klaus.mailinglists@pernau.at
> <mailto:klaus.mailinglists@pernau.at >>
> > > <mailto: klaus.mailinglists@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@lists.openser.org
> <mailto:Users@lists.openser.org> <mailto:Users@lists.openser.org
> <mailto:Users@lists.openser.org>>
> > <mailto: Users@lists.openser.org
> <mailto: Users@lists.openser.org> <mailto: Users@lists.openser.org
> <mailto:Users@lists.openser.org >>>
> > > > http://lists.openser.org/cgi-bin/mailman/listinfo/users
> > >
> > >
> > >
> > >
> > > --
> > > Fengbin
> > >
> >
> >
> >
> >
> > --
> > Fengbin
>
>
>
>
> --
> Fengbin