Hi All
When I start openser using
/usr/local/sbin/openser it loads then I login using one user and I keep
gettingthe logs below all the time is this normal
Feb 1 14:03:54 [29077] DBG:core:parse_headers: flags=78
Feb 1 14:03:54 [29077] DBG:tm:t_lookup_request: start searching:
hash=50458, isACK=0
Feb 1 14:03:54 [29077] DBG:tm:matching_3261: RFC3261 transaction
matched, tid=-d87543-5c484340d1308708-1--d87543-
Feb 1 14:03:54 [29077] DBG:tm:t_lookup_request: REF_UNSAFE: after is 1
Feb 1 14:03:54 [29077] DBG:tm:t_lookup_request: transaction found
(T=0x4069bb80)
Feb 1 14:03:54 [29077] DBG:tm:t_retransmit_reply: nothing to retransmit
Feb 1 14:03:54 [29077] DBG:tm:t_unref: UNREF_UNSAFE: after is 0
Feb 1 14:03:54 [29077] DBG:core:destroy_avp_list: destroying list (nil)
Feb 1 14:03:54 [29077] DBG:core:receive_msg: cleaning up
Feb 1 14:03:54 [29078] DBG:tm:utimer_routine: timer
routine:7,tl=0x4069bccc next=(nil), timeout=12700000
Feb 1 14:03:54 [29078] DBG:tm:retransmission_handler:
retransmission_handler : request resending (t=0x4069bb80, SUBSCRIBE ...
)
Feb 1 14:03:54 [29078] DBG:tm:set_timer: relative timeout is 4000000
Feb 1 14:03:54 [29078] DBG:tm:insert_timer_unsafe: [7]: 0x4069bccc
(16700000)
Feb 1 14:03:54 [29078] DBG:tm:retransmission_handler:
retransmission_handler : done
Feb 1 14:03:58 [29075] DBG:core:parse_msg: SIP Request:
Feb 1 14:03:58 [29075] DBG:core:parse_msg: method: <SUBSCRIBE>
Feb 1 14:03:58 [29075] DBG:core:parse_msg: uri:
<sip:ali@jabber.splendor.net>
Feb 1 14:03:58 [29075] DBG:core:parse_msg: version: <SIP/2.0>
Feb 1 14:03:58 [29075] DBG:core:parse_headers: flags=2
Feb 1 14:03:58 [29075] DBG:core:parse_via_param: found param type 232,
<branch> = <z9hG4bK-d87543-5c484340d1308708-1--d87543->; state=6
Feb 1 14:03:58 [29075] DBG:core:parse_via_param: found param type 235,
<rport> = <n/a>; state=17
Feb 1 14:03:58 [29075] DBG:core:parse_via: end of header reached,
state=5
Feb 1 14:03:58 [29075] DBG:core:parse_headers: via found, flags=2
Feb 1 14:03:58 [29075] DBG:core:parse_headers: this is the first via
Feb 1 14:03:58 [29075] DBG:core:receive_msg: After parse_msg...
Feb 1 14:03:58 [29075] DBG:core:receive_msg: preparing to run routing
scripts...
Feb 1 14:03:58 [29075] DBG:core:parse_headers: flags=100
Feb 1 14:03:58 [29075] DBG:maxfwd:is_maxfwd_present: value = 70
Feb 1 14:03:58 [29075] DBG:core:parse_headers: flags=200
Feb 1 14:03:58 [29075] DBG:core:parse_to: end of header reached,
state=10
Feb 1 14:03:58 [29075] DBG:core:parse_to: display={"ssafass"},
ruri={sip:ali@jabber.splendor.net}
Feb 1 14:03:58 [29075] DBG:core:get_hdr_field: <To> [40];
uri=[sip:ali@jabber.splendor.net]
Feb 1 14:03:58 [29075] DBG:core:get_hdr_field: to body
["ssafass"<sip:ali@jabber.splendor.net>
]
Feb 1 14:03:58 [29075] DBG:core:get_hdr_field: cseq <CSeq>: <1>
<SUBSCRIBE>
Feb 1 14:03:58 [29075] DBG:core:get_hdr_field: content_length=0
Feb 1 14:03:58 [29075] DBG:core:get_hdr_field: found end of header
Feb 1 14:03:58 [29075] DBG:rr:find_first_route: No Route headers found
Feb 1 14:03:58 [29075] DBG:rr:loose_route: There is no Route HF
Feb 1 14:03:58 [29075] DBG:core:grep_sock_info: checking if host==us:
19==15 && [
jabber.splendor.net] == [193.227.186.153]
Feb 1 14:03:58 [29075] DBG:core:grep_sock_info: checking if port 5060
matches port 5060
Feb 1 14:03:58 [29075] DBG:uri_db:does_uri_exist: User in request uri
does exist
Feb 1 14:03:58 [29075] DBG:core:db_free_rows: freeing 1 rows
Feb 1 14:03:58 [29075] DBG:core:db_free_rows: row[0]=0x81841e0
Feb 1 14:03:58 [29075] DBG:core:db_free_rows: 0x81841e0=pkg_free()
RES_ROWS
Feb 1 14:03:58 [29075] DBG:core:rewrite_uri: rewriting Request-URI with
'sip:ali@193.227.186.146:6242;rinstance=63a8660ec1b35169'
Feb 1 14:03:58 [29075] DBG:tm:t_newtran: transaction on
entrance=0xffffffff
Feb 1 14:03:58 [29075] DBG:core:parse_headers: flags=ffffffffffffffff
Feb 1 14:03:58 [29075] DBG:core:parse_headers: flags=78
Feb 1 14:03:58 [29075] DBG:tm:t_lookup_request: start searching:
hash=50458, isACK=0
Feb 1 14:03:58 [29075] DBG:tm:matching_3261: RFC3261 transaction
matched, tid=-d87543-5c484340d1308708-1--d87543-
Feb 1 14:03:58 [29075] DBG:tm:t_lookup_request: REF_UNSAFE: after is 1
Feb 1 14:03:58 [29075] DBG:tm:t_lookup_request: transaction found
(T=0x4069bb80)
Feb 1 14:03:58 [29075] DBG:tm:t_retransmit_reply: nothing to retransmit
Feb 1 14:03:58 [29075] DBG:tm:t_unref: UNREF_UNSAFE: after is 0
Feb 1 14:03:58 [29075] DBG:core:destroy_avp_list: destroying list (nil)
Feb 1 14:03:58 [29075] DBG:core:receive_msg: cleaning up
Feb 1 14:03:58 [29078] DBG:tm:utimer_routine: timer
routine:7,tl=0x4069bccc next=(nil), timeout=16700000
Feb 1 14:03:58 [29078] DBG:tm:retransmission_handler:
retransmission_handler : request resending (t=0x4069bb80, SUBSCRIBE ...
)
Feb 1 14:03:58 [29078] DBG:tm:set_timer: relative timeout is 4000000
Feb 1 14:03:58 [29078] DBG:tm:insert_timer_unsafe: [7]: 0x4069bccc
(20700000)
Feb 1 14:03:58 [29078] DBG:tm:retransmission_handler:
retransmission_handler : done
Feb 1 14:04:02 [29077] DBG:core:parse_msg: SIP Request:
Feb 1 14:04:02 [29077] DBG:core:parse_msg: method: <SUBSCRIBE>
Feb 1 14:04:02 [29077] DBG:core:parse_msg: uri:
<sip:ali@jabber.splendor.net>
Feb 1 14:04:02 [29077] DBG:core:parse_msg: version: <SIP/2.0>
Feb 1 14:04:02 [29077] DBG:core:parse_headers: flags=2
Feb 1 14:04:02 [29077] DBG:core:parse_via_param: found param type 232,
<branch> = <z9hG4bK-d87543-5c484340d1308708-1--d87543->; state=6
Feb 1 14:04:02 [29077] DBG:core:parse_via_param: found param type 235,
<rport> = <n/a>; state=17
Feb 1 14:04:02 [29077] DBG:core:parse_via: end of header reached,
state=5
Feb 1 14:04:02 [29077] DBG:core:parse_headers: via found, flags=2
Feb 1 14:04:02 [29077] DBG:core:parse_headers: this is the first via
Feb 1 14:04:02 [29077] DBG:core:receive_msg: After parse_msg...
Feb 1 14:04:02 [29077] DBG:core:receive_msg: preparing to run routing
scripts...
Feb 1 14:04:02 [29077] DBG:core:parse_headers: flags=100
Feb 1 14:04:02 [29077] DBG:maxfwd:is_maxfwd_present: value = 70
Feb 1 14:04:02 [29077] DBG:core:parse_headers: flags=200
Feb 1 14:04:02 [29077] DBG:core:parse_to: end of header reached,
state=10
Feb 1 14:04:02 [29077] DBG:core:parse_to: display={"ssafass"},
ruri={sip:ali@jabber.splendor.net}
Feb 1 14:04:02 [29077] DBG:core:get_hdr_field: <To> [40];
uri=[sip:ali@jabber.splendor.net]
Feb 1 14:04:02 [29077] DBG:core:get_hdr_field: to body
["ssafass"<sip:ali@jabber.splendor.net>
]
Feb 1 14:04:02 [29077] DBG:core:get_hdr_field: cseq <CSeq>: <1>
<SUBSCRIBE>
Feb 1 14:04:02 [29077] DBG:core:get_hdr_field: content_length=0
Feb 1 14:04:02 [29077] DBG:core:get_hdr_field: found end of header
Feb 1 14:04:02 [29077] DBG:rr:find_first_route: No Route headers found
Feb 1 14:04:02 [29077] DBG:rr:loose_route: There is no Route HF
Feb 1 14:04:02 [29077] DBG:core:grep_sock_info: checking if host==us:
19==15 && [
jabber.splendor.net] == [193.227.186.153]
Feb 1 14:04:02 [29077] DBG:core:grep_sock_info: checking if port 5060
matches port 5060
Feb 1 14:04:02 [29077] DBG:uri_db:does_uri_exist: User in request uri
does exist
Feb 1 14:04:02 [29077] DBG:core:db_free_rows: freeing 1 rows
Feb 1 14:04:02 [29077] DBG:core:db_free_rows: row[0]=0x817fca0
Feb 1 14:04:02 [29077] DBG:core:db_free_rows: 0x817fca0=pkg_free()
RES_ROWS
Feb 1 14:04:02 [29077] DBG:core:rewrite_uri: rewriting Request-URI with
'sip:ali@193.227.186.146:6242;rinstance=63a8660ec1b35169'
Feb 1 14:04:02 [29077] DBG:tm:t_newtran: transaction on
entrance=0xffffffff
Feb 1 14:04:02 [29077] DBG:core:parse_headers: flags=ffffffffffffffff
Feb 1 14:04:02 [29077] DBG:core:parse_headers: flags=78
Feb 1 14:04:02 [29077] DBG:tm:t_lookup_request: start searching:
hash=50458, isACK=0
Feb 1 14:04:02 [29077] DBG:tm:matching_3261: RFC3261 transaction
matched, tid=-d87543-5c484340d1308708-1--d87543-
Feb 1 14:04:02 [29077] DBG:tm:t_lookup_request: REF_UNSAFE: after is 1
Feb 1 14:04:02 [29077] DBG:tm:t_lookup_request: transaction found
(T=0x4069bb80)
Feb 1 14:04:02 [29077] DBG:tm:t_retransmit_reply: nothing to retransmit
Feb 1 14:04:02 [29077] DBG:tm:t_unref: UNREF_UNSAFE: after is 0
Feb 1 14:04:02 [29077] DBG:core:destroy_avp_list: destroying list (nil)
Feb 1 14:04:02 [29077] DBG:core:receive_msg: cleaning up
Feb 1 14:04:02 [29078] DBG:tm:utimer_routine: timer
routine:7,tl=0x4069bccc next=(nil), timeout=20700000
Feb 1 14:04:02 [29078] DBG:tm:retransmission_handler:
retransmission_handler : request resending (t=0x4069bb80, SUBSCRIBE ...
)
Feb 1 14:04:02 [29078] DBG:tm:set_timer: relative timeout is 4000000
Feb 1 14:04:02 [29078] DBG:tm:insert_timer_unsafe: [7]: 0x4069bccc
(24700000)
Feb 1 14:04:02 [29078] DBG:tm:retransmission_handler:
retransmission_handler : done
Feb 1 14:04:06 [29075] DBG:core:parse_msg: SIP Request:
Feb 1 14:04:06 [29075] DBG:core:parse_msg: method: <SUBSCRIBE>
Feb 1 14:04:06 [29075] DBG:core:parse_msg: uri:
<sip:ali@jabber.splendor.net>
Feb 1 14:04:06 [29075] DBG:core:parse_msg: version: <SIP/2.0>
Feb 1 14:04:06 [29075] DBG:core:parse_headers: flags=2
Feb 1 14:04:06 [29075] DBG:core:parse_via_param: found param type 232,
<branch> = <z9hG4bK-d87543-5c484340d1308708-1--d87543->; state=6
Feb 1 14:04:06 [29075] DBG:core:parse_via_param: found param type 235,
<rport> = <n/a>; state=17
Feb 1 14:04:06 [29075] DBG:core:parse_via: end of header reached,
state=5
Feb 1 14:04:06 [29075] DBG:core:parse_headers: via found, flags=2
Feb 1 14:04:06 [29075] DBG:core:parse_headers: this is the first via
Feb 1 14:04:06 [29075] DBG:core:receive_msg: After parse_msg...
Feb 1 14:04:06 [29075] DBG:core:receive_msg: preparing to run routing
scripts...
Feb 1 14:04:06 [29075] DBG:core:parse_headers: flags=100
Feb 1 14:04:06 [29075] DBG:maxfwd:is_maxfwd_present: value = 70
Feb 1 14:04:06 [29075] DBG:core:parse_headers: flags=200
Feb 1 14:04:06 [29075] DBG:core:parse_to: end of header reached,
state=10
Feb 1 14:04:06 [29075] DBG:core:parse_to: display={"ssafass"},
ruri={sip:ali@jabber.splendor.net}
Feb 1 14:04:06 [29075] DBG:core:get_hdr_field: <To> [40];
uri=[sip:ali@jabber.splendor.net]
Feb 1 14:04:06 [29075] DBG:core:get_hdr_field: to body
["ssafass"<sip:ali@jabber.splendor.net>
]
Feb 1 14:04:06 [29075] DBG:core:get_hdr_field: cseq <CSeq>: <1>
<SUBSCRIBE>
Feb 1 14:04:06 [29075] DBG:core:get_hdr_field: content_length=0
Feb 1 14:04:06 [29075] DBG:core:get_hdr_field: found end of header
Feb 1 14:04:06 [29075] DBG:rr:find_first_route: No Route headers found
Feb 1 14:04:06 [29075] DBG:rr:loose_route: There is no Route HF
Feb 1 14:04:06 [29075] DBG:core:grep_sock_info: checking if host==us:
19==15 && [
jabber.splendor.net] == [193.227.186.153]
Feb 1 14:04:06 [29075] DBG:core:grep_sock_info: checking if port 5060
matches port 5060
Feb 1 14:04:06 [29075] DBG:uri_db:does_uri_exist: User in request uri
does exist
Feb 1 14:04:06 [29075] DBG:core:db_free_rows: freeing 1 rows
Feb 1 14:04:06 [29075] DBG:core:db_free_rows: row[0]=0x817fcc8
Feb 1 14:04:06 [29075] DBG:core:db_free_rows: 0x817fcc8=pkg_free()
RES_ROWS
Feb 1 14:04:06 [29075] DBG:core:rewrite_uri: rewriting Request-URI with
'sip:ali@193.227.186.146:6242;rinstance=63a8660ec1b35169'
Feb 1 14:04:06 [29075] DBG:tm:t_newtran: transaction on
entrance=0xffffffff
Feb 1 14:04:06 [29075] DBG:core:parse_headers: flags=ffffffffffffffff
Feb 1 14:04:06 [29075] DBG:core:parse_headers: flags=78
Feb 1 14:04:06 [29075] DBG:tm:t_lookup_request: start searching:
hash=50458, isACK=0
Feb 1 14:04:06 [29075] DBG:tm:matching_3261: RFC3261 transaction
matched, tid=-d87543-5c484340d1308708-1--d87543-
Feb 1 14:04:06 [29075] DBG:tm:t_lookup_request: REF_UNSAFE: after is 1
Feb 1 14:04:06 [29075] DBG:tm:t_lookup_request: transaction found
(T=0x4069bb80)
Feb 1 14:04:06 [29075] DBG:tm:t_retransmit_reply: nothing to retransmit
Feb 1 14:04:06 [29075] DBG:tm:t_unref: UNREF_UNSAFE: after is 0
Feb 1 14:04:06 [29075] DBG:core:destroy_avp_list: destroying list (nil)
Feb 1 14:04:06 [29075] DBG:core:receive_msg: cleaning up
Feb 1 14:04:06 [29078] DBG:tm:utimer_routine: timer
routine:7,tl=0x4069bccc next=(nil), timeout=24700000
Feb 1 14:04:06 [29078] DBG:tm:retransmission_handler:
retransmission_handler : request resending (t=0x4069bb80, SUBSCRIBE ...
)
Feb 1 14:04:06 [29078] DBG:tm:set_timer: relative timeout is 4000000
Feb 1 14:04:06 [29078] DBG:tm:insert_timer_unsafe: [7]: 0x4069bccc
(28700000)
Feb 1 14:04:06 [29078] DBG:tm:retransmission_handler:
retransmission_handler : done
Feb 1 14:04:10 [29077] DBG:core:parse_msg: SIP Request:
Feb 1 14:04:10 [29077] DBG:core:parse_msg: method: <SUBSCRIBE>
Feb 1 14:04:10 [29077] DBG:core:parse_msg: uri:
<sip:ali@jabber.splendor.net>
Feb 1 14:04:10 [29077] DBG:core:parse_msg: version: <SIP/2.0>
Feb 1 14:04:10 [29077] DBG:core:parse_headers: flags=2
Feb 1 14:04:10 [29077] DBG:core:parse_via_param: found param type 232,
<branch> = <z9hG4bK-d87543-5c484340d1308708-1--d87543->; state=6
Feb 1 14:04:10 [29077] DBG:core:parse_via_param: found param type 235,
<rport> = <n/a>; state=17
Feb 1 14:04:10 [29077] DBG:core:parse_via: end of header reached,
state=5
Feb 1 14:04:10 [29077] DBG:core:parse_headers: via found, flags=2
Feb 1 14:04:10 [29077] DBG:core:parse_headers: this is the first via
Feb 1 14:04:10 [29077] DBG:core:receive_msg: After parse_msg...
Feb 1 14:04:10 [29077] DBG:core:receive_msg: preparing to run routing
scripts...
Feb 1 14:04:10 [29077] DBG:core:parse_headers: flags=100
Feb 1 14:04:10 [29077] DBG:maxfwd:is_maxfwd_present: value = 70
Feb 1 14:04:10 [29077] DBG:core:parse_headers: flags=200
Feb 1 14:04:10 [29077] DBG:core:parse_to: end of header reached,
state=10
Feb 1 14:04:10 [29077] DBG:core:parse_to: display={"ssafass"},
ruri={sip:ali@jabber.splendor.net}
Feb 1 14:04:10 [29077] DBG:core:get_hdr_field: <To> [40];
uri=[sip:ali@jabber.splendor.net]
Feb 1 14:04:10 [29077] DBG:core:get_hdr_field: to body
["ssafass"<sip:ali@jabber.splendor.net>
]
Feb 1 14:04:10 [29077] DBG:core:get_hdr_field: cseq <CSeq>: <1>
<SUBSCRIBE>
Feb 1 14:04:10 [29077] DBG:core:get_hdr_field: content_length=0
Feb 1 14:04:10 [29077] DBG:core:get_hdr_field: found end of header
Feb 1 14:04:10 [29077] DBG:rr:find_first_route: No Route headers found
Feb 1 14:04:10 [29077] DBG:rr:loose_route: There is no Route HF
Feb 1 14:04:10 [29077] DBG:core:grep_sock_info: checking if host==us:
19==15 && [
jabber.splendor.net] == [193.227.186.153]
Feb 1 14:04:10 [29077] DBG:core:grep_sock_info: checking if port 5060
matches port 5060
Feb 1 14:04:10 [29077] DBG:uri_db:does_uri_exist: User in request uri
does exist
Feb 1 14:04:10 [29077] DBG:core:db_free_rows: freeing 1 rows
Feb 1 14:04:10 [29077] DBG:core:db_free_rows: row[0]=0x8179d78
Feb 1 14:04:10 [29077] DBG:core:db_free_rows: 0x8179d78=pkg_free()
RES_ROWS
Feb 1 14:04:10 [29077] DBG:core:rewrite_uri: rewriting Request-URI with
'sip:ali@193.227.186.146:6242;rinstance=63a8660ec1b35169'
Feb 1 14:04:10 [29077] DBG:tm:t_newtran: transaction on
entrance=0xffffffff
Feb 1 14:04:10 [29077] DBG:core:parse_headers: flags=ffffffffffffffff
Feb 1 14:04:10 [29077] DBG:core:parse_headers: flags=78
Feb 1 14:04:10 [29077] DBG:tm:t_lookup_request: start searching:
hash=50458, isACK=0
Feb 1 14:04:10 [29077] DBG:tm:matching_3261: RFC3261 transaction
matched, tid=-d87543-5c484340d1308708-1--d87543-
Feb 1 14:04:10 [29077] DBG:tm:t_lookup_request: REF_UNSAFE: after is 1
Feb 1 14:04:10 [29077] DBG:tm:t_lookup_request: transaction found
(T=0x4069bb80)
Feb 1 14:04:10 [29077] DBG:tm:t_retransmit_reply: nothing to retransmit
Feb 1 14:04:10 [29077] DBG:tm:t_unref: UNREF_UNSAFE: after is 0
Feb 1 14:04:10 [29077] DBG:core:destroy_avp_list: destroying list (nil)
Feb 1 14:04:10 [29077] DBG:core:receive_msg: cleaning up
Feb 1 14:04:10 [29078] DBG:tm:utimer_routine: timer
routine:7,tl=0x4069bccc next=(nil), timeout=28700000
Feb 1 14:04:10 [29078] DBG:tm:retransmission_handler:
retransmission_handler : request resending (t=0x4069bb80, SUBSCRIBE ...
)
Feb 1 14:04:10 [29078] DBG:tm:set_timer: relative timeout is 4000000
Feb 1 14:04:10 [29078] DBG:tm:insert_timer_unsafe: [7]: 0x4069bccc
(32700000)
Feb 1 14:04:10 [29078] DBG:tm:retransmission_handler:
retransmission_handler : done
Feb 1 14:04:11 [29075] DBG:core:udp_rcv_loop: probing packet received
from 193.227.186.146 11518
Feb 1 14:04:12 [29078] DBG:tm:timer_routine: timer
routine:0,tl=0x4069bce8 next=0x4069bdfc, timeout=31
Feb 1 14:04:12 [29078] DBG:tm:final_response_handler: stop retr. and
send CANCEL (0x4069bb80)
Feb 1 14:04:12 [29078] DBG:tm:t_should_relay_response: T_code=0,
new_code=408
Feb 1 14:04:12 [29078] DBG:tm:t_pick_branch: picked branch 0, code 408
Feb 1 14:04:12 [29078] DBG:tm:is_3263_failure: dns-failover test:
branch=0, last_recv=408, flags=0
Feb 1 14:04:12 [29078] DBG:tm:t_should_relay_response: trying DNS-based
failover
Feb 1 14:04:12 [29078] DBG:tm:relay_reply: branch=0, save=0, relay=0
Feb 1 14:04:12 [29078] DBG:core:parse_headers: flags=ffffffffffffffff
Feb 1 14:04:12 [29078] DBG:core:check_via_address: params
193.227.186.146, 192.168.0.176, 0
Feb 1 14:04:12 [29078] DBG:core:_shm_resize: resize(0) called
Feb 1 14:04:12 [29078] DBG:tm:insert_timer_unsafe: [2]: 0x4069bbc8 (36)
Feb 1 14:04:12 [29078] DBG:tm:relay_reply: sent buf=0x8179e70: SIP/2.0
4..., shmem=0x40699c70: SIP/2.0 4
Feb 1 14:04:12 [29078] DBG:tm:final_response_handler: done
Feb 1 14:04:12 [29078] DBG:tm:timer_routine: timer
routine:0,tl=0x4069bdfc next=(nil), timeout=31