[Users] SIPS in openSER

Christoph Fürstaller christoph.fuerstaller at kurtkrenn.com
Mon Mar 27 21:26:20 CEST 2006 

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
 
Hi Bogdan,

Sry, didn't thought when I sent the logs. Here is the debug output
with an error 500.

chris...

Bogdan-Andrei Iancu schrieb:
> Hi Christoph,
>
> the log shows a working REGISTER. can you please provide a log with
> failing INVITE (containing the error you were refereing at).
>
> regards, bogdan
>
> Christoph Fürstaller wrote:
>
> Hi Bogdan,
>
> Ok, if UDP is needed by this protocol then it shouldn't function
> without it.
>
> I attached the debuging output from openSER when the snom tries to
> login.
>
> What are the Contact entries? Are they because the phone didn't
> unregistered correctly? I just pluged it off and an again to see
> the login output. All this entries are in the location table in my
> db.
>
> chris...
>
> Bogdan-Andrei Iancu wrote:
>
>
>>>> Hi Cris,
>>>>
>>>> thanks for you info
>>>>
>>>> Christoph Fürstaller wrote:
>>>>
>>>>
>>>>> -----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
>>>>>
>>>>> Hi Bogdan, I still get the same 'error' with another phone.
>>>>> A snom 190. If I connect it to an TLS only SER I get thd
>>>>> "500 I'm terribly sorry, server error occurred (7/TM)". If
>>>>> I open up UDP as well the phone registeres fine with SER.
>>>>>
>>>>> I read another posting which sayes: " If I remember
>>>>> correctly
> the RFC,
>>>>> UDP is mandatory for a SIP server" Is this correct? I don't
>>>>>
> know it.
>>>>>
>>>>>
>>>>>
>>>> yes, UDP is mandatory as protocol.
>>>>
>>>>
>>>>> I attached my cfg. It's the one coming with tls-openSER and
>>>>> i think you wrote it : )
>>>>>
>>>>>
>>>>>
>>>> ok - I will take a look, but please give me also the RURI
>>>> sent
> by the
>>>> SNOM (it is essential) - I will try to locate the problem
>>>>
>>>> regards, bogdan
>>>>
>
>>>
> ------------------------------------------------------------------------
>
>>>
> 11(26780) tcpconn_new: new tcp connection to: 192.168.20.187
> 11(26780) tcpconn_new: on port 2049, type 3 11(26780)
> tls_tcpconn_init: Entered: Creating a whole new ssl connection
> 11(26780) tls_tcpconn_init: Looking up tls domain
> [192.168.20.156:5061] 11(26780) tls_tcpconn_init: Using default tls
> server settings 11(26780) tls_tcpconn_init: Setting in ACCEPT mode
> (server) 11(26780) tcpconn_add: hashes: 193, 209 11(26780)
> handle_new_connect: new connection: 0x4060b6c8 25 flags: 0002
> 11(26780) send2child: to tcp child 0 7(26766), 0x4060b6c8 7(26766)
> received n=4 con=0x4060b6c8, fd=20 7(26766) DBG:
> io_watch_add(0x80f17c0, 20, 2, 0x4060b6c8), fd_no=1 7(26766)
> tls_update_fd: New fd is 20 7(26766) tls_update_fd: New fd is 20
> 7(26766) tls_accept: TLS handshake successful 7(26766)
> tls_update_fd: New fd is 20 7(26766) tls_update_fd: New fd is 20
> 7(26766) tls_update_fd: New fd is 20 7(26766) _tls_read: 866 bytes
> read 7(26766) tcp_read_req: content-length= 0 7(26766) SIP Request:
>  7(26766)  method:  <REGISTER> 7(26766)  uri:
> <sip:192.168.20.156:5061;transport=tls> 7(26766)  version:
> <SIP/2.0> 7(26766) parse_headers: flags=2 7(26766) Found param type
> 232, <branch> = <z9hG4bK-xwuy1h54dryy>; state=6 7(26766) Found
> param type 235, <rport> = <n/a>; state=17 7(26766) end of header
> reached, state=5 7(26766) parse_headers: Via found, flags=2
> 7(26766) parse_headers: this is the first via 7(26766) After
> parse_msg... 7(26766) preparing to run routing scripts... 7(26766)
> parse_headers: flags=100 7(26766) DEBUG:parse_to:end of header
> reached, state=9 7(26766) DEBUG: get_hdr_field: <To> [53];
> uri=[sip:test at 192.168.20.156:5061;transport=tls] 7(26766) DEBUG: to
> body ["test" <sip:test at 192.168.20.156:5061;transport=tls> ]
> 7(26766) get_hdr_field: cseq <CSeq>: <1> <REGISTER> 7(26766)
> DEBUG:maxfwd:is_maxfwd_present: value = 70 7(26766) parse_headers:
> flags=200 7(26766) DEBUG: get_hdr_body : content_length=0 7(26766)
> found end of header 7(26766) find_first_route: No Route headers
> found 7(26766) loose_route: There is no Route HF 7(26766)
> grep_sock_info - checking if host==us: 14==14 && [192.168.20.156]
> == [192.168.20.156] 7(26766) grep_sock_info - checking if port 5060
> matches port 5061 7(26766) grep_sock_info - checking if host==us:
> 14==14 && [192.168.20.156] == [192.168.20.156] 7(26766)
> grep_sock_info - checking if port 5061 matches port 5061 7(26766)
> grep_sock_info - checking if host==us: 14==14 && [192.168.20.156]
> == [192.168.20.156] 7(26766) grep_sock_info - checking if port 5060
> matches port 5061 7(26766) grep_sock_info - checking if host==us:
> 14==14 && [192.168.20.156] == [192.168.20.156] 7(26766)
> grep_sock_info - checking if port 5061 matches port 5061 7(26766)
> parse_headers: flags=4000 7(26766) pre_auth(): Credentials with
> given realm not found 7(26766) build_auth_hf(): 'WWW-Authenticate:
> Digest realm="192.168.20.156",
> nonce="4423cd4c884708795300456efae3cc8121e7155c" ' 7(26766)
> parse_headers: flags=ffffffffffffffff 7(26766)
> check_via_address(192.168.20.187, 192.168.20.187, 0) 7(26766)
> tcp_send: tcp connection found (0x4060b6c8), acquiring fd 7(26766)
> tcp_send, c= 0x4060b6c8, n=8 11(26780) handle_ser_child: read
> response= 4060b6c8, 1, fd -1 from 7 (26766) 7(26766) tcp_send:
> after receive_fd: c= 0x4060b6c8 n=4 fd=21 7(26766) tcp_send:
> sending... 7(26766) tls_update_fd: New fd is 21 7(26766) tls_write:
> Write was successful (722 bytes) 7(26766) tcp_send: after write: c=
> 0x4060b6c8 n=722 fd=21 7(26766) tcp_send: buf= SIP/2.0 401
> Unauthorized Via: SIP/2.0/TLS
> 192.168.20.187:2049;branch=z9hG4bK-xwuy1h54dryy;rport=2049 From:
> "test" <sip:test at 192.168.20.156:5061;transport=tls>;tag=3ntprlhika
> To: "test"
> <sip:test at 192.168.20.156:5061;transport=tls>;tag=010b4fa55c4d08d1039c6a916bb5ecdc.9c39
>  Call-ID: 3c26700a0c35-l9lq3hhij6ml at snom190 CSeq: 1 REGISTER
> WWW-Authenticate: Digest realm="192.168.20.156",
> nonce="4423cd4c884708795300456efae3cc8121e7155c" Server: OpenSer
> (1.1.0-dev16 -tls (i386/linux)) Content-Length: 0 Warning: 392
> 192.168.20.156:5061 "Noisy feedback tells:  pid=26766
> req_src_ip=192.168.20.187 req_src_port=2049
> in_uri=sip:192.168.20.156:5061;transport=tls
> out_uri=sip:192.168.20.156:5061;transport=tls via_cnt==1"
>>>
>>>
> 7(26766) DEBUG:destroy_avp_list: destroying list (nil) 7(26766)
> receive_msg: cleaning up 7(26766) tls_update_fd: New fd is 20
> 7(26766) tls_update_fd: New fd is 20 7(26766) tls_update_fd: New fd
> is 20 7(26766) _tls_read: 1079 bytes read 7(26766) tcp_read_req:
> content-length= 0 7(26766) SIP Request: 7(26766)  method:
> <REGISTER> 7(26766)  uri:
> <sip:192.168.20.156:5061;transport=tls> 7(26766)  version:
> <SIP/2.0> 7(26766) parse_headers: flags=2 7(26766) Found param type
> 232, <branch> = <z9hG4bK-6fjbha0qxrtw>; state=6 7(26766) Found
> param type 235, <rport> = <n/a>; state=17 7(26766) end of header
> reached, state=5 7(26766) parse_headers: Via found, flags=2
> 7(26766) parse_headers: this is the first via 7(26766) After
> parse_msg... 7(26766) preparing to run routing scripts... 7(26766)
> parse_headers: flags=100 7(26766) DEBUG:parse_to:end of header
> reached, state=9 7(26766) DEBUG: get_hdr_field: <To> [53];
> uri=[sip:test at 192.168.20.156:5061;transport=tls] 7(26766) DEBUG: to
> body ["test" <sip:test at 192.168.20.156:5061;transport=tls> ]
> 7(26766) get_hdr_field: cseq <CSeq>: <2> <REGISTER> 7(26766)
> DEBUG:maxfwd:is_maxfwd_present: value = 70 7(26766) parse_headers:
> flags=200 7(26766) DEBUG: get_hdr_body : content_length=0 7(26766)
> found end of header 7(26766) find_first_route: No Route headers
> found 7(26766) loose_route: There is no Route HF 7(26766)
> grep_sock_info - checking if host==us: 14==14 && [192.168.20.156]
> == [192.168.20.156] 7(26766) grep_sock_info - checking if port 5060
> matches port 5061 7(26766) grep_sock_info - checking if host==us:
> 14==14 && [192.168.20.156] == [192.168.20.156] 7(26766)
> grep_sock_info - checking if port 5061 matches port 5061 7(26766)
> grep_sock_info - checking if host==us: 14==14 && [192.168.20.156]
> == [192.168.20.156] 7(26766) grep_sock_info - checking if port 5060
> matches port 5061 7(26766) grep_sock_info - checking if host==us:
> 14==14 && [192.168.20.156] == [192.168.20.156] 7(26766)
> grep_sock_info - checking if port 5061 matches port 5061 7(26766)
> check_nonce(): comparing [4423cd4c884708795300456efae3cc8121e7155c]
> and [4423cd4c884708795300456efae3cc8121e7155c] 7(26766) HA1 string
> calculated: 53ee6c16b5102c59afa23cbd21a6d936 7(26766)
> check_response(): Our result = '5eea837512ca0655ce1369c41b5185b6'
> 7(26766) check_response(): Authorization is OK 7(26766)
> parse_headers: flags=ffffffffffffffff 7(26766) parse_headers:
> flags=8000000 7(26766) build_contact(): Created Contact HF:
> Contact:
> <sip:test at 192.168.20.187:2253;transport=tls;line=4f5o4cc1>;q=1;expires=246,
> 
> <sip:test at 192.168.20.187:2254;transport=tls;line=4f5o4cc1>;q=1;expires=759,
> 
> <sip:test at 192.168.20.187:2255;transport=tls;line=4f5o4cc1>;q=1;expires=1073,
> 
> <sip:test at 192.168.20.187:2256;transport=tls;line=4f5o4cc1>;q=1;expires=1538,
> 
> <sip:test at 192.168.20.187:2257;transport=tls;line=4f5o4cc1>;q=1;expires=1849,
> 
> <sip:test at 192.168.20.187:2258;transport=tls;line=4f5o4cc1>;q=1;expires=2150,
> 
> <sip:test at 192.168.20.187:2259;transport=tls;line=4f5o4cc1>;q=1;expires=2637,
> 
> <sip:test at 192.168.20.187:2260;transport=tls;line=4f5o4cc1>;q=1;expires=3022,
> 
> <sip:test at 192.168.20.187:2261;transport=tls;line=4f5o4cc1>;q=1;expires=3323,
> 
> <sip:test at 192.168.20.187:2049;transport=tls;line=xxzpplzh>;q=1;expires=3442,
> 
> <sip:test at 192.168.20.187:2049;transport=tls;line=kshlnn3b>;q=1;expires=3600
>
>>>
> 7(26766) parse_headers: flags=ffffffffffffffff 7(26766)
> check_via_address(192.168.20.187, 192.168.20.187, 0) 7(26766)
> tcp_send: tcp connection found (0x4060b6c8), acquiring fd 7(26766)
> tcp_send, c= 0x4060b6c8, n=8 11(26780) handle_ser_child: read
> response= 4060b6c8, 1, fd -1 from 7 (26766) 7(26766) tcp_send:
> after receive_fd: c= 0x4060b6c8 n=4 fd=21 7(26766) tcp_send:
> sending... 7(26766) tls_update_fd: New fd is 21 7(26766) tls_write:
> Write was successful (1467 bytes) 7(26766) tcp_send: after write:
> c= 0x4060b6c8 n=1467 fd=21 7(26766) tcp_send: buf= SIP/2.0 200 OK
> Via: SIP/2.0/TLS
> 192.168.20.187:2049;branch=z9hG4bK-6fjbha0qxrtw;rport=2049 From:
> "test" <sip:test at 192.168.20.156:5061;transport=tls>;tag=3ntprlhika
> To: "test"
> <sip:test at 192.168.20.156:5061;transport=tls>;tag=010b4fa55c4d08d1039c6a916bb5ecdc.a59e
>  Call-ID: 3c26700a0c35-l9lq3hhij6ml at snom190 CSeq: 2 REGISTER
> Contact:
> <sip:test at 192.168.20.187:2253;transport=tls;line=4f5o4cc1>;q=1;expires=246,
> 
> <sip:test at 192.168.20.187:2254;transport=tls;line=4f5o4cc1>;q=1;expires=759,
> 
> <sip:test at 192.168.20.187:2255;transport=tls;line=4f5o4cc1>;q=1;expires=1073,
> 
> <sip:test at 192.168.20.187:2256;transport=tls;line=4f5o4cc1>;q=1;expires=1538,
> 
> <sip:test at 192.168.20.187:2257;transport=tls;line=4f5o4cc1>;q=1;expires=1849,
> 
> <sip:test at 192.168.20.187:2258;transport=tls;line=4f5o4cc1>;q=1;expires=2150,
> 
> <sip:test at 192.168.20.187:2259;transport=tls;line=4f5o4cc1>;q=1;expires=2637,
> 
> <sip:test at 192.168.20.187:2260;transport=tls;line=4f5o4cc1>;q=1;expires=3022,
> 
> <sip:test at 192.168.20.187:2261;transport=tls;line=4f5o4cc1>;q=1;expires=3323,
> 
> <sip:test at 192.168.20.187:2049;transport=tls;line=xxzpplzh>;q=1;expires=3442,
> 
> <sip:test at 192.168.20.187:2049;transport=tls;line=kshlnn3b>;q=1;expires=3600
>  Server: OpenSer (1.1.0-dev16 -tls (i386/linux)) Content-Length: 0
> Warning: 392 192.168.20.156:5061 "Noisy feedback tells:  pid=26766
> req_src_ip=192.168.20.187 req_src_port=2049
> in_uri=sip:192.168.20.156:5061;transport=tls
> out_uri=sip:192.168.20.156:5061;transport=tls via_cnt==1"
>>>
>>>
> 7(26766) DEBUG:destroy_avp_list: destroying list (nil) 7(26766)
> receive_msg: cleaning up 7(26766) tcp_receive_loop: 0x4060b6c8
> expired (81329, 81330) 7(26766) DBG: io_watch_del (0x80f17c0, 20,
> -1, 0x10) fd_no=2 called 7(26766) releasing con 0x4060b6c8, state
> 0, fd=20, id=209 7(26766)  extra_data 0x405dad88 11(26780)
> handle_tcp_child: reader response= 4060b6c8, 0 from 0 11(26780)
> DBG: io_watch_add(0x80f14a0, 25, 2, 0x4060b6c8), fd_no=15 11(26780)
> handle_tcp_child: CONN_RELEASE  0x4060b6c8 refcnt= 0
>
>>>
> ------------------------------------------------------------------------
>
>>>
> _______________________________________________ Users mailing list
> Users at openser.org http://openser.org/cgi-bin/mailman/listinfo/users
>
>
>>>
>
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.1 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org
 
iD8DBQFEKDxbR0exH8dhr/YRAg4DAJ4+hLWSQf6K8bdl5ooXbR1713lC4wCg2gh9
TUCBM7BMg82DiNM25RhMuvg=
=yvu8
-----END PGP SIGNATURE-----

-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: openser_dbug.txt
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20060327/24551a99/attachment.txt>

More information about the sr-users mailing list