[OpenSIPS-Users] Help please - OpenSIPS Runtime Errors

Khan Friend khansfriend at gmail.com
Tue Jan 6 04:19:02 CET 2009 

Hello everyone,

I am having runtime errors in OpenSIPS, I have tried to locate the root of
the problem but being newbee I'm confused where does the problem lies. I
have Debian running with OpenSIPS, Asterisks, RTPproxy, MySQL database
running.

I have debian machine running all those servers, when i do ifconfig i get
following response:

eth0      Link encap:UNSPEC  HWaddr
00-60-1D-00-00-00-05-B2-00-00-00-00-00-00-00-00
          inet addr:192.168.1.2  Bcast:192.168.1.255  Mask:255.255.255.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:230 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:0 (0.0 B)  TX bytes:18984 (18.5 KiB)

eth1      Link encap:Ethernet  HWaddr 00:c0:49:63:64:a0
          inet addr:192.168.1.2  Bcast:192.168.1.255  Mask:255.255.255.0
          inet6 addr: fe80::2c0:49ff:fe63:64a0/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:22591 errors:0 dropped:0 overruns:0 frame:0
          TX packets:22471 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:8050374 (7.6 MiB)  TX bytes:3810685 (3.6 MiB)
          Interrupt:169 Base address:0xd800

lo        Link encap:Local Loopback
          inet addr:127.0.0.1  Mask:255.0.0.0
          inet6 addr: ::1/128 Scope:Host
          UP LOOPBACK RUNNING  MTU:16436  Metric:1
          RX packets:7184 errors:0 dropped:0 overruns:0 frame:0
          TX packets:7184 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:3347190 (3.1 MiB)  TX bytes:3347190 (3.1 MiB)


when i register my X-lite within the network it registers fine. when i look
in log i see error

Jan  5 20:38:15myosips[5021]: ERROR:core:forward_reply: no 2nd via found in
reply

I tried changing script many ways, finally i put a simple script but still
facing same problem. Can somone tell me where is the problem.

some of the things i see as problem is listed below but complet log is
attached.

#######################

Jan  5 20:37:17myosips[5017]: DBG:core:db_do_init: connection 0x819ed30 not
found in pool
Jan  5 20:37:17myosips[5017]: DBG:db_mysql:db_mysql_new_connection: opening
connection: mysql://xxxx:xxxx@localhost/opensips
Jan  5 20:37:17myosips[5017]: DBG:db_mysql:db_mysql_new_connection:
connection type is Localhost via UNIX socket
Jan  5 20:37:17myosips[5017]: DBG:db_mysql:db_mysql_new_connection: protocol
version is 10
Jan  5 20:37:17myosips[5017]: DBG:db_mysql:db_mysql_new_connection: server
version is 5.0.75-1
Jan  5 20:37:17myosips[5017]: DBG:core:db_new_result: allocate 28 bytes for
result set at 0x819edf0
Jan  5 20:37:17myosips[5017]: DBG:db_mysql:db_mysql_get_columns: 1 columns
returned from the query
Jan  5 20:37:17myosips[5017]: DBG:core:db_allocate_columns: allocate 4 bytes
for result names at 0x819ee18
Jan  5 20:37:17myosips[5017]: DBG:core:db_allocate_columns: allocate 4 bytes
for result types at 0x819ee28
Jan  5 20:37:17myosips[5017]: DBG:db_mysql:db_mysql_get_columns: allocate 8
bytes for RES_NAMES[0] at 0x819ee38
Jan  5 20:37:17myosips[5017]: DBG:db_mysql:db_mysql_get_columns:
RES_NAMES(0x819ee38)[0]=[table_version]
Jan  5 20:37:17myosips[5017]: DBG:db_mysql:db_mysql_get_columns: use DB_INT
result type
Jan  5 20:37:17myosips[5017]: DBG:db_mysql:db_mysql_convert_rows: allocate 8
bytes for rows at 0x819ee48
Jan  5 20:37:17myosips[5017]: DBG:db_mysql:db_mysql_convert_row: allocate 20
bytes for row values at 0x819ee58
Jan  5 20:37:17myosips[5017]: DBG:db_mysql:db_mysql_str2val: converting INT
[6]


Jan  5 20:38:15myosips[5021]: DBG:core:parse_msg: SIP Request:
Jan  5 20:38:15myosips[5021]: DBG:core:parse_msg:  method:  <OPTIONS>
Jan  5 20:38:15myosips[5021]: DBG:core:parse_msg:  uri:     <sip:domain.com>

Jan  5 20:38:15myosips[5021]: DBG:core:parse_msg:  version: <SIP/2.0>
Jan  5 20:38:15myosips[5021]: DBG:core:parse_headers: flags=2
Jan  5 20:38:15myosips[5021]: DBG:core:parse_via_param: found param type
232, <branch> = <z9hG4bK0a6fc1db>; state=6
Jan  5 20:38:15myosips[5021]: DBG:core:parse_via_param: found param type
235, <rport> = <n/a>; state=17
Jan  5 20:38:15myosips[5021]: DBG:core:parse_via: end of header reached,
state=5
Jan  5 20:38:15myosips[5021]: DBG:core:parse_headers: via found, flags=2
Jan  5 20:38:15myosips[5021]: DBG:core:parse_headers: this is the first via
Jan  5 20:38:15myosips[5021]: DBG:core:receive_msg: After parse_msg...
Jan  5 20:38:15myosips[5021]: DBG:core:receive_msg: preparing to run routing
scripts...
Jan  5 20:38:15myosips[5021]: DBG:core:parse_headers: flags=100
Jan  5 20:38:15myosips[5021]: DBG:core:parse_to: end of header reached,
state=10
Jan  5 20:38:15myosips[5021]: DBG:core:parse_to: display={}, ruri={sip:
domain.com}
Jan  5 20:38:15myosips[5021]: DBG:core:get_hdr_field: <To> [22]; uri=[sip:
domain.com]
Jan  5 20:38:15myosips[5021]: DBG:core:get_hdr_field: to body [<sip:
domain.com>^M ]
Jan  5 20:38:15myosips[5021]: DBG:core:get_hdr_field: cseq <CSeq>: <102>
<OPTIONS>
Jan  5 20:38:15myosips[5021]: DBG:maxfwd:is_maxfwd_present: value = 70
Jan  5 20:38:15myosips[5021]: DBG:core:parse_headers: flags=200
Jan  5 20:38:15myosips[5021]: DBG:core:get_hdr_field: content_length=0
Jan  5 20:38:15myosips[5021]: DBG:core:get_hdr_field: found end of header
Jan  5 20:38:15myosips[5021]: DBG:rr:find_first_route: No Route headers
found
Jan  5 20:38:15myosips[5021]: DBG:rr:loose_route: There is no Route HF
Jan  5 20:38:15myosips[5021]: DBG:core:parse_headers: flags=78
Jan  5 20:38:15myosips[5021]: DBG:tm:t_lookup_request: start searching:
hash=52593, isACK=0
Jan  5 20:38:15myosips[5021]: DBG:tm:matching_3261: RFC3261 transaction
matching failed
Jan  5 20:38:15myosips[5021]: DBG:tm:t_lookup_request: no transaction found
Jan  5 20:38:15myosips[5021]: DBG:core:parse_to_param: tag=as713a3254
Jan  5 20:38:15myosips[5021]: DBG:core:parse_to: end of header reached,
state=29
Jan  5 20:38:15myosips[5021]: DBG:core:parse_to: display={"asterisk"},
ruri={sip:asterisk at 192.168.1.2 <sip%3Aasterisk at 192.168.1.2>}
Jan  5 20:38:15myosips[5021]: DBG:core:db_new_result: allocate 28 bytes for
result set at 0x81ad548
Jan  5 20:38:15myosips[5021]: DBG:db_mysql:db_mysql_get_columns: 1 columns
returned from the query
Jan  5 20:38:15myosips[5021]: DBG:core:db_allocate_columns: allocate 4 bytes
for result names at 0x81ad570
Jan  5 20:38:15myosips[5021]: DBG:core:db_allocate_columns: allocate 4 bytes
for result types at 0x81ad580
Jan  5 20:38:15myosips[5021]: DBG:db_mysql:db_mysql_get_columns: allocate 8
bytes for RES_NAMES[0] at 0x81ad590
Jan  5 20:38:15myosips[5021]: DBG:db_mysql:db_mysql_get_columns:
RES_NAMES(0x81ad590)[0]=[domain]
Jan  5 20:38:15myosips[5021]: DBG:db_mysql:db_mysql_get_columns: use
DB_STRING result type
Jan  5 20:38:15myosips[5021]: DBG:db_mysql:db_mysql_convert_rows: allocate 8
bytes for rows at 0x81ad5a0
Jan  5 20:38:15myosips[5021]: DBG:db_mysql:db_mysql_convert_row: allocate 20
bytes for row values at 0x81ad5b0
Jan  5 20:38:15myosips[5021]: DBG:db_mysql:db_mysql_str2val: converting
STRING [192.168.1.2]
Jan  5 20:38:15myosips[5021]: DBG:domain:is_domain_local: Realm
'192.168.1.2' is local
Jan  5 20:38:15myosips[5021]: DBG:core:db_free_columns: freeing 1 columns
Jan  5 20:38:15myosips[5021]: DBG:core:db_free_columns: freeing RES_NAMES[0]
at 0x81ad590
Jan  5 20:38:15myosips[5021]: DBG:core:db_free_columns: freeing result names
at 0x81ad570
Jan  5 20:38:15myosips[5021]: DBG:core:db_free_columns: freeing result types
at 0x81ad580
Jan  5 20:38:15myosips[5021]: DBG:core:db_free_rows: freeing 1 rows
Jan  5 20:38:15myosips[5021]: DBG:core:db_free_row: freeing row values at
0x81ad5b0
Jan  5 20:38:15myosips[5021]: DBG:core:db_free_rows: freeing rows at
0x81ad5a0
Jan  5 20:38:15myosips[5021]: DBG:core:db_free_result: freeing result set at
0x81ad548
Jan  5 20:38:15myosips[5021]: DBG:core:parse_headers: flags=10000
Jan  5 20:38:15myosips[5021]: DBG:auth:pre_auth: credentials with given
realm not found
Jan  5 20:38:15myosips[5021]: DBG:auth:reserve_nonce_index: second= 57,
sec_monit= -1,  index= 2
Jan  5 20:38:15myosips[5021]: DBG:auth:build_auth_hf: nonce index= 2
Jan  5 20:38:15myosips[5021]: DBG:auth:build_auth_hf: 'Proxy-Authenticate:
Digest realm="192.168.1.2",
nonce="4962c54300000002524467c57860866dca83727f8a80f9b4", qop="auth"^M '
Jan  5 20:38:15myosips[5021]: DBG:core:parse_headers: flags=ffffffffffffffff

Jan  5 20:38:15myosips[5021]: DBG:core:check_via_address: params
192.168.1.2, 192.168.1.2, 0
Jan  5 20:38:15myosips[5021]: DBG:core:destroy_avp_list: destroying list
(nil)
Jan  5 20:38:15myosips[5021]: DBG:core:receive_msg: cleaning up
Jan  5 20:38:15myosips[5021]: DBG:core:parse_msg: SIP Reply  (status):
Jan  5 20:38:15myosips[5021]: DBG:core:parse_msg:  version: <SIP/2.0>
Jan  5 20:38:15myosips[5021]: DBG:core:parse_msg:  status:  <407>
Jan  5 20:38:15myosips[5021]: DBG:core:parse_msg:  reason:  <Proxy
Authentication Required>
Jan  5 20:38:15myosips[5021]: DBG:core:parse_headers: flags=2
Jan  5 20:38:15myosips[5021]: DBG:core:parse_via_param: found param type
232, <branch> = <z9hG4bK0a6fc1db>; state=6
Jan  5 20:38:15myosips[5021]: DBG:core:parse_via_param: found param type
235, <rport> = <5060>; state=16
Jan  5 20:38:15myosips[5021]: DBG:core:parse_via: end of header reached,
state=5
Jan  5 20:38:15myosips[5021]: DBG:core:parse_headers: via found, flags=2
Jan  5 20:38:15myosips[5021]: DBG:core:parse_headers: this is the first via
Jan  5 20:38:15myosips[5021]: DBG:core:receive_msg: After parse_msg...
Jan  5 20:38:15myosips[5021]: DBG:core:forward_reply: found module tm,
passing reply to it
Jan  5 20:38:15myosips[5021]: DBG:tm:t_check: start=0xffffffff
Jan  5 20:38:15myosips[5021]: DBG:core:parse_headers: flags=22
Jan  5 20:38:15myosips[5021]: DBG:core:parse_to_param:
tag=69f8afbb50c9344b26c64cd60f28e76d.ec15
Jan  5 20:38:15myosips[5021]: DBG:core:parse_to: end of header reached,
state=29
Jan  5 20:38:15myosips[5021]: DBG:core:parse_to: display={}, ruri={sip:
domain.com}
Jan  5 20:38:15myosips[5021]: DBG:core:get_hdr_field: <To> [64]; uri=[sip:
domain.com]
Jan  5 20:38:15myosips[5021]: DBG:core:get_hdr_field: to body [<sip:
domain.com>]
Jan  5 20:38:15myosips[5021]: DBG:core:get_hdr_field: cseq <CSeq>: <102>
<OPTIONS>
Jan  5 20:38:15myosips[5021]: DBG:tm:t_reply_matching: failure to match a
transaction
Jan  5 20:38:15myosips[5021]: DBG:tm:t_check: end=(nil)
Jan  5 20:38:15myosips[5021]: DBG:core:parse_headers: flags=4
Jan  5 20:38:15myosips[5021]: DBG:core:get_hdr_field: content_length=0
Jan  5 20:38:15myosips[5021]: DBG:core:get_hdr_field: found end of header
Jan  5 20:38:15myosips[5021]: ERROR:core:forward_reply: no 2nd via found in
reply
Jan  5 20:38:15myosips[5021]: DBG:core:destroy_avp_list: destroying list
(nil)
Jan  5 20:38:15myosips[5021]: DBG:core:receive_msg: cleaning up


#######################


Thank you,

Khan
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.opensips.org/pipermail/users/attachments/20090105/14d48864/attachment-0001.htm

More information about the Users mailing list