Jul  4 13:27:30 openser-pri openser[26017]: SIP Request: 
Jul  4 13:27:30 openser-pri openser[26017]:  method:  <REGISTER> 
Jul  4 13:27:30 openser-pri openser[26017]:  uri:     <sip:barik.com> 
Jul  4 13:27:30 openser-pri openser[26017]:  version: <SIP/2.0> 
Jul  4 13:27:30 openser-pri openser[26017]: parse_headers: flags=2 
Jul  4 13:27:30 openser-pri openser[26017]: Found param type 232, <branch> = <z9hG4bKbfc21b6a9f7bf8863>; state=16 
Jul  4 13:27:30 openser-pri openser[26017]: end of header reached, state=5 
Jul  4 13:27:30 openser-pri openser[26017]: parse_headers: Via found, flags=2 
Jul  4 13:27:30 openser-pri openser[26017]: parse_headers: this is the first via 
Jul  4 13:27:30 openser-pri openser[26017]: After parse_msg... 
Jul  4 13:27:30 openser-pri openser[26017]: preparing to run routing scripts... 
Jul  4 13:27:30 openser-pri openser[26017]: parse_headers: flags=100 
Jul  4 13:27:30 openser-pri openser[26017]: DEBUG:maxfwd:is_maxfwd_present: value = 70  
Jul  4 13:27:30 openser-pri openser[26017]: parse_headers: flags=200 
Jul  4 13:27:30 openser-pri openser[26017]: DEBUG:parse_to:end of header reached, state=10 
Jul  4 13:27:30 openser-pri openser[26017]: DBUG:parse_to: display={}, ruri={sip:104@barik.com} 
Jul  4 13:27:30 openser-pri openser[26017]: DEBUG: get_hdr_field: <To> [21]; uri=[sip:104@barik.com]  
Jul  4 13:27:30 openser-pri openser[26017]: DEBUG: to body [<sip:104@barik.com>^M ] 
Jul  4 13:27:30 openser-pri openser[26017]: get_hdr_field: cseq <CSeq>: <28799> <REGISTER> 
Jul  4 13:27:30 openser-pri openser[26017]: DEBUG: get_hdr_body : content_length=0 
Jul  4 13:27:30 openser-pri openser[26017]: found end of header 
Jul  4 13:27:30 openser-pri openser[26017]: find_first_route: No Route headers found 
Jul  4 13:27:30 openser-pri openser[26017]: loose_route: There is no Route HF 
Jul  4 13:27:30 openser-pri openser[26017]: parse_headers: flags=ffffffffffffffff 
Jul  4 13:27:30 openser-pri openser[26017]: check_via_address(192.168.100.125, 192.168.100.125, 0) 
Jul  4 13:27:30 openser-pri openser[26017]: allow_source_address(): looking for <0, 7d64a8c0, 1063> 
Jul  4 13:27:30 openser-pri openser[26017]: check_nonce(): comparing [468b774db68cdc9f1d09517ccb2e18b5be044544] and [468b774db68cdc9f1d09517ccb2e18b5be044544] 
Jul  4 13:27:30 openser-pri openser[26017]: HA1 string calculated: a82436e751d294d84ef44a51a6bfeec5 
Jul  4 13:27:30 openser-pri openser[26017]: check_response(): Our result = '867e24ae348eb2cff53c4de46d95f65f' 
Jul  4 13:27:30 openser-pri openser[26017]: check_response(): Authorization is OK 
Jul  4 13:27:30 openser-pri openser[26017]: post_auth(): Response is OK, but nonce is stale 
Jul  4 13:27:30 openser-pri openser[26017]: DEBUG: add_param: tag=e0d95b5974 
Jul  4 13:27:30 openser-pri openser[26017]: DEBUG:parse_to:end of header reached, state=29 
Jul  4 13:27:30 openser-pri openser[26017]: DBUG:parse_to: display={}, ruri={sip:104@barik.com} 
Jul  4 13:27:30 openser-pri openser[26017]: OPENSER_NAME: 107 route[REGISTER][2] \^M         ^Isip:104@barik.com Authorization for sip:104@barik.com (192.168.100.125) requested 
Jul  4 13:27:30 openser-pri openser[26017]: build_auth_hf(): 'WWW-Authenticate: Digest realm="barik.com", nonce="468b854e634013995a7ceeacaa5d94adaf48d8a7", stale=true^M ' 
Jul  4 13:27:30 openser-pri openser[26017]: parse_headers: flags=ffffffffffffffff 
Jul  4 13:27:30 openser-pri openser[26017]: check_via_address(192.168.100.125, 192.168.100.125, 0) 
Jul  4 13:27:30 openser-pri openser[26017]: DEBUG:destroy_avp_list: destroying list (nil) 
Jul  4 13:27:30 openser-pri openser[26017]: receive_msg: cleaning up 
Jul  4 13:27:30 openser-pri openser[26015]: SIP Request: 
Jul  4 13:27:30 openser-pri openser[26015]:  method:  <REGISTER> 
Jul  4 13:27:30 openser-pri openser[26015]:  uri:     <sip:barik.com> 
Jul  4 13:27:30 openser-pri openser[26015]:  version: <SIP/2.0> 
Jul  4 13:27:30 openser-pri openser[26015]: parse_headers: flags=2 
Jul  4 13:27:30 openser-pri openser[26015]: Found param type 232, <branch> = <z9hG4bKb2076151a9f1c58f1>; state=16 
Jul  4 13:27:30 openser-pri openser[26015]: end of header reached, state=5 
Jul  4 13:27:30 openser-pri openser[26015]: parse_headers: Via found, flags=2 
Jul  4 13:27:30 openser-pri openser[26015]: parse_headers: this is the first via 
Jul  4 13:27:30 openser-pri openser[26015]: After parse_msg... 
Jul  4 13:27:30 openser-pri openser[26015]: preparing to run routing scripts... 
Jul  4 13:27:30 openser-pri openser[26015]: parse_headers: flags=100 
Jul  4 13:27:30 openser-pri openser[26015]: DEBUG:maxfwd:is_maxfwd_present: value = 70  
Jul  4 13:27:30 openser-pri openser[26015]: parse_headers: flags=200 
Jul  4 13:27:30 openser-pri openser[26015]: DEBUG:parse_to:end of header reached, state=10 
Jul  4 13:27:30 openser-pri openser[26015]: DBUG:parse_to: display={}, ruri={sip:104@barik.com} 
Jul  4 13:27:30 openser-pri openser[26015]: DEBUG: get_hdr_field: <To> [21]; uri=[sip:104@barik.com]  
Jul  4 13:27:30 openser-pri openser[26015]: DEBUG: to body [<sip:104@barik.com>^M ] 
Jul  4 13:27:30 openser-pri openser[26015]: get_hdr_field: cseq <CSeq>: <28800> <REGISTER> 
Jul  4 13:27:30 openser-pri openser[26015]: DEBUG: get_hdr_body : content_length=0 
Jul  4 13:27:30 openser-pri openser[26015]: found end of header 
Jul  4 13:27:30 openser-pri openser[26015]: find_first_route: No Route headers found 
Jul  4 13:27:30 openser-pri openser[26015]: loose_route: There is no Route HF 
Jul  4 13:27:30 openser-pri openser[26015]: parse_headers: flags=ffffffffffffffff 
Jul  4 13:27:30 openser-pri openser[26015]: check_via_address(192.168.100.125, 192.168.100.125, 0) 
Jul  4 13:27:30 openser-pri openser[26015]: allow_source_address(): looking for <0, 7d64a8c0, 1063> 
Jul  4 13:27:30 openser-pri openser[26015]: check_nonce(): comparing [468b854e634013995a7ceeacaa5d94adaf48d8a7] and [468b854e634013995a7ceeacaa5d94adaf48d8a7] 
Jul  4 13:27:30 openser-pri openser[26015]: HA1 string calculated: a82436e751d294d84ef44a51a6bfeec5 
Jul  4 13:27:30 openser-pri openser[26015]: check_response(): Our result = '93d62760d0a2eb1ac0a93917e83bb760' 
Jul  4 13:27:30 openser-pri openser[26015]: check_response(): Authorization is OK 
Jul  4 13:27:30 openser-pri openser[26015]: generate_avps: set string AVP "rpid"/0 = "aaa" 
Jul  4 13:27:30 openser-pri openser[26015]: DEBUG: add_param: tag=e0d95b5974 
Jul  4 13:27:30 openser-pri openser[26015]: DEBUG:parse_to:end of header reached, state=29 
Jul  4 13:27:30 openser-pri openser[26015]: DBUG:parse_to: display={}, ruri={sip:104@barik.com} 
Jul  4 13:27:30 openser-pri openser[26015]: OPENSER_NAME: 143 route[REGISTER][2] \^M       ^I^Isip:104@barik.com Authorization OK 
Jul  4 13:27:30 openser-pri openser[26015]: check_username(): Digest username and URI username match 
Jul  4 13:27:30 openser-pri openser[26015]: parse_headers: flags=ffffffffffffffff 
Jul  4 13:27:30 openser-pri openser[26015]: parse_headers: flags=8000000 
Jul  4 13:27:30 openser-pri openser[26015]: parse_headers: flags=ffffffffffffffff 
Jul  4 13:27:30 openser-pri openser[26015]: build_contact(): Created Contact HF: Contact: <sip:104@192.168.100.125:5060;transport=udp>;expires=3600^M  
Jul  4 13:27:30 openser-pri openser[26015]: parse_headers: flags=ffffffffffffffff 
Jul  4 13:27:30 openser-pri openser[26015]: check_via_address(192.168.100.125, 192.168.100.125, 0) 
Jul  4 13:27:30 openser-pri openser[26015]: OPENSER_NAME: 143 route[REGISTER][2] \^M         ^I^Isip:104@barik.com save(location)OK 
Jul  4 13:27:30 openser-pri openser[26015]: DEBUG: t_newtran:  T on entrance=0xffffffff 
Jul  4 13:27:30 openser-pri openser[26015]: parse_headers: flags=ffffffffffffffff 
Jul  4 13:27:30 openser-pri openser[26015]: parse_headers: flags=78 
Jul  4 13:27:30 openser-pri openser[26015]: t_lookup_request: start searching: hash=17627, isACK=0 
Jul  4 13:27:30 openser-pri openser[26015]: DEBUG: RFC3261 transaction matching failed 
Jul  4 13:27:30 openser-pri openser[26015]: DEBUG: t_lookup_request: no transaction found 
Jul  4 13:27:30 openser-pri openser[26015]: DBG: trans=0xb56dc0f8, callback type 1, id 1 entered 
Jul  4 13:27:30 openser-pri openser[26015]: DBG: trans=0xb56dc0f8, callback type 1, id 0 entered 
Jul  4 13:27:30 openser-pri openser[26015]: DEBUG: mk_proxy: doing DNS lookup... 
Jul  4 13:27:30 openser-pri openser[26015]: check_via_address(192.168.100.125, 192.168.100.125, 0) 
Jul  4 13:27:30 openser-pri openser[26015]: DBG:check_against_rule_list: using list dns  
Jul  4 13:27:30 openser-pri openser[26015]: DEBUG:tm:set_timer: relative timeout is 500000 
Jul  4 13:27:30 openser-pri openser[26015]: DEBUG: add_to_tail_of_timer[4]: 0xb56dc244 (6057600000) 
Jul  4 13:27:30 openser-pri openser[26015]: DEBUG:tm:set_timer: relative timeout is 10 
Jul  4 13:27:30 openser-pri openser[26015]: DEBUG: add_to_tail_of_timer[0]: 0xb56dc260 (6067) 
Jul  4 13:27:30 openser-pri openser[26015]: DEBUG:tm:t_relay_to: new transaction fwd'ed 
Jul  4 13:27:30 openser-pri openser[26015]: DEBUG:tm:UNREF_UNSAFE: after is 0 
Jul  4 13:27:30 openser-pri openser[26015]: DEBUG:destroy_avp_list: destroying list (nil) 
Jul  4 13:27:30 openser-pri openser[26015]: receive_msg: cleaning up 
Jul  4 13:27:30 openser-pri openser[26012]: SIP Reply  (status): 
Jul  4 13:27:30 openser-pri openser[26012]:  version: <SIP/2.0> 
Jul  4 13:27:30 openser-pri openser[26012]:  status:  <100> 
Jul  4 13:27:30 openser-pri openser[26012]:  reason:  <Trying> 
Jul  4 13:27:30 openser-pri openser[26012]: parse_headers: flags=2 
Jul  4 13:27:30 openser-pri openser[26012]: Found param type 232, <branch> = <z9hG4bKbd44.2aaaa41.0>; state=16 
Jul  4 13:27:30 openser-pri openser[26012]: end of header reached, state=5 
Jul  4 13:27:30 openser-pri openser[26012]: parse_headers: Via found, flags=2 
Jul  4 13:27:30 openser-pri openser[26012]: parse_headers: this is the first via 
Jul  4 13:27:30 openser-pri openser[26012]: After parse_msg... 
Jul  4 13:27:30 openser-pri openser[26012]: DEBUG:forward_reply: found module tm, passing reply to it 
Jul  4 13:27:30 openser-pri openser[26012]: DEBUG: t_check: start=0xffffffff 
Jul  4 13:27:30 openser-pri openser[26012]: parse_headers: flags=22 
Jul  4 13:27:30 openser-pri openser[26012]: Found param type 232, <branch> = <z9hG4bKb2076151a9f1c58f1>; state=16 
Jul  4 13:27:30 openser-pri openser[26012]: end of header reached, state=5 
Jul  4 13:27:30 openser-pri openser[26012]: parse_headers: Via found, flags=22 
Jul  4 13:27:30 openser-pri openser[26012]: parse_headers: this is the second via 
Jul  4 13:27:30 openser-pri openser[26016]: SIP Reply  (status): 
Jul  4 13:27:30 openser-pri openser[26012]: DEBUG:parse_to:end of header reached, state=10 
Jul  4 13:27:30 openser-pri openser[26016]:  version: <SIP/2.0> 
Jul  4 13:27:30 openser-pri openser[26012]: DBUG:parse_to: display={}, ruri={sip:104@barik.com} 
Jul  4 13:27:30 openser-pri openser[26016]:  status:  <200> 
Jul  4 13:27:30 openser-pri openser[26012]: DEBUG: get_hdr_field: <To> [21]; uri=[sip:104@barik.com]  
Jul  4 13:27:30 openser-pri openser[26016]:  reason:  <OK> 
Jul  4 13:27:30 openser-pri openser[26012]: DEBUG: to body [<sip:104@barik.com>^M ] 
Jul  4 13:27:30 openser-pri openser[26016]: parse_headers: flags=2 
Jul  4 13:27:30 openser-pri openser[26012]: get_hdr_field: cseq <CSeq>: <28800> <REGISTER> 
Jul  4 13:27:30 openser-pri openser[26016]: Found param type 232, <branch> = <z9hG4bKbd44.2aaaa41.0>; state=16 
Jul  4 13:27:30 openser-pri openser[26012]: DEBUG: t_reply_matching: hash 17627 label 21670562 branch 0 
Jul  4 13:27:30 openser-pri openser[26016]: end of header reached, state=5 
Jul  4 13:27:30 openser-pri openser[26012]: DEBUG:tm:REF_UNSAFE: after is 1 
Jul  4 13:27:30 openser-pri openser[26016]: parse_headers: Via found, flags=2 
Jul  4 13:27:30 openser-pri openser[26012]: DEBUG: t_reply_matching: reply matched (T=0xb56dc0f8)! 
Jul  4 13:27:30 openser-pri openser[26016]: parse_headers: this is the first via 
Jul  4 13:27:30 openser-pri openser[26012]: DEBUG: t_check: end=0xb56dc0f8 
Jul  4 13:27:30 openser-pri openser[26016]: After parse_msg... 
Jul  4 13:27:30 openser-pri openser[26012]: DEBUG:tm:reply_received: org. status uas=0, uac[0]=0 local=2 is_invite=0) 
Jul  4 13:27:30 openser-pri openser[26016]: DEBUG:forward_reply: found module tm, passing reply to it 
Jul  4 13:27:30 openser-pri openser[26012]: DEBUG:tm:t_should_relay_response: T_code=0, new_code=100 
Jul  4 13:27:30 openser-pri openser[26016]: DEBUG: t_check: start=0xffffffff 
Jul  4 13:27:30 openser-pri openser[26012]: DEBUG:tm:local_reply: branch=0, save=0, winner=-1 
Jul  4 13:27:30 openser-pri openser[26016]: parse_headers: flags=22 
Jul  4 13:27:30 openser-pri openser[26012]: DEBUG:tm:set_timer: relative timeout is 4000000 
Jul  4 13:27:30 openser-pri openser[26016]: Found param type 232, <branch> = <z9hG4bKb2076151a9f1c58f1>; state=16 
Jul  4 13:27:30 openser-pri openser[26012]: DEBUG: add_to_tail_of_timer[7]: 0xb56dc244 (6061100000) 
Jul  4 13:27:30 openser-pri openser[26016]: end of header reached, state=5 
Jul  4 13:27:30 openser-pri openser[26012]: DEBUG:tm:UNREF_UNSAFE: after is 0 
Jul  4 13:27:30 openser-pri openser[26016]: parse_headers: Via found, flags=22 
Jul  4 13:27:30 openser-pri openser[26012]: DEBUG:destroy_avp_list: destroying list (nil) 
Jul  4 13:27:30 openser-pri openser[26016]: parse_headers: this is the second via 
Jul  4 13:27:30 openser-pri openser[26012]: receive_msg: cleaning up 
Jul  4 13:27:30 openser-pri openser[26016]: DEBUG: add_param: tag=ca5e1177438f93230637db845b5db61b.3e3e 
Jul  4 13:27:30 openser-pri openser[26016]: DEBUG:parse_to:end of header reached, state=29 
Jul  4 13:27:30 openser-pri openser[26016]: DBUG:parse_to: display={}, ruri={sip:104@barik.com} 
Jul  4 13:27:30 openser-pri openser[26016]: DEBUG: get_hdr_field: <To> [63]; uri=[sip:104@barik.com]  
Jul  4 13:27:30 openser-pri openser[26016]: DEBUG: to body [<sip:104@barik.com>] 
Jul  4 13:27:30 openser-pri openser[26016]: get_hdr_field: cseq <CSeq>: <28800> <REGISTER> 
Jul  4 13:27:30 openser-pri openser[26016]: DEBUG: t_reply_matching: hash 17627 label 21670562 branch 0 
Jul  4 13:27:30 openser-pri openser[26016]: DEBUG:tm:REF_UNSAFE: after is 1 
Jul  4 13:27:30 openser-pri openser[26016]: DEBUG: t_reply_matching: reply matched (T=0xb56dc0f8)! 
Jul  4 13:27:30 openser-pri openser[26016]: DEBUG: t_check: end=0xb56dc0f8 
Jul  4 13:27:30 openser-pri openser[26016]: DEBUG:tm:reply_received: org. status uas=0, uac[0]=100 local=2 is_invite=0) 
Jul  4 13:27:30 openser-pri openser[26016]: DEBUG:tm:t_should_relay_response: T_code=0, new_code=200 
Jul  4 13:27:30 openser-pri openser[26016]: DEBUG:tm:local_reply: branch=0, save=0, winner=0 
Jul  4 13:27:30 openser-pri openser[26016]: DEBUG:tm:local_reply: local transaction completed 
Jul  4 13:27:30 openser-pri openser[26016]: DEBUG: cleanup_uac_timers: RETR/FR timers reset 
Jul  4 13:27:30 openser-pri openser[26016]: DEBUG: add_to_tail_of_timer[2]: 0xb56dc140 (6062) 
Jul  4 13:27:30 openser-pri openser[26016]: DEBUG:tm:UNREF_UNSAFE: after is 0 
Jul  4 13:27:30 openser-pri openser[26016]: DEBUG:destroy_avp_list: destroying list (nil) 
Jul  4 13:27:30 openser-pri openser[26016]: receive_msg: cleaning up 
Jul  4 13:27:34 openser-pri openser[26018]: DEBUG: timer routine:7,tl=0xb56dc244 next=(nil), timeout=6061100000 
Jul  4 13:27:35 openser-pri openser[26018]: DEBUG: timer routine:2,tl=0xb56dc140 next=(nil), timeout=6062 
Jul  4 13:27:35 openser-pri openser[26018]: DEBUG: wait_handler : removing 0xb56dc0f8 from table  
Jul  4 13:27:35 openser-pri openser[26018]: DEBUG: delete transaction 0xb56dc0f8 
Jul  4 13:27:35 openser-pri openser[26018]: DEBUG: wait_handler : done 
Jul  4 13:39:01 openser-pri /USR/SBIN/CRON[26877]: (root) CMD (  [ -d /var/lib/php4 ] && find /var/lib/php4/ -type f -cmin +$(/usr/lib/php4/maxlifetime) -print0 | xargs -r -0 rm)
Jul  4 13:39:01 openser-pri /USR/SBIN/CRON[26879]: (root) CMD (  [ -d /var/lib/php5 ] && find /var/lib/php5/ -type f -cmin +$(/usr/lib/php5/maxlifetime) -print0 | xargs -r -0 rm)
Jul  4 13:39:10 openser-pri openser[26896]: DEBUG: mi_xmlrpc: default_method: starting up..... 
Jul  4 13:39:10 openser-pri openser[26896]: DEBUG: mi_xmlrpc: default_method: Done looking the mi command. 
Jul  4 13:39:10 openser-pri openser[26896]: DEBUG: mi_xmlrpc: default_method: Done parsing the mi tree. 
Jul  4 13:39:10 openser-pri openser[26896]: db_init: Connection 'mysql://openser:openserrw@192.168.1.130/openser' found in pool 
Jul  4 13:39:10 openser-pri openser[26896]: pool_remove: Connection still kept in the pool 
Jul  4 13:39:10 openser-pri openser[26896]: DEBUG: mi_xmlrpc: default_method: Done running the mi command. 
Jul  4 13:39:10 openser-pri openser[26896]: DEBUG: mi_xmlrpc: default_method: Done building response. 
Jul  4 13:40:37 openser-pri openser[26897]: DEBUG: mi_xmlrpc: default_method: starting up..... 
Jul  4 13:40:37 openser-pri openser[26897]: DEBUG: mi_xmlrpc: default_method: Done looking the mi command. 
Jul  4 13:40:37 openser-pri openser[26897]: DEBUG: mi_xmlrpc: default_method: Done parsing the mi tree. 
Jul  4 13:40:37 openser-pri openser[26897]: DEBUG: mi_xmlrpc: default_method: Done running the mi command. 
Jul  4 13:40:37 openser-pri openser[26897]: DEBUG: mi_xmlrpc: default_method: Done building response. 
Jul  4 13:54:05 openser-pri openser[26898]: DEBUG: mi_xmlrpc: default_method: starting up..... 
Jul  4 13:54:05 openser-pri openser[26898]: DEBUG: mi_xmlrpc: default_method: Done looking the mi command. 
Jul  4 13:54:05 openser-pri openser[26898]: DEBUG: mi_xmlrpc: default_method: Done parsing the mi tree. 
Jul  4 13:54:05 openser-pri openser[26898]: DEBUG: mi_xmlrpc: default_method: Done running the mi command. 
Jul  4 13:54:05 openser-pri openser[26898]: DEBUG: mi_xmlrpc: xr_build_response: Command processing failure: AOR not found 
Jul  4 13:54:56 openser-pri openser[26899]: DEBUG: mi_xmlrpc: default_method: starting up..... 
Jul  4 13:54:56 openser-pri openser[26899]: DEBUG: mi_xmlrpc: default_method: Done looking the mi command. 
Jul  4 13:54:56 openser-pri openser[26899]: DEBUG: mi_xmlrpc: default_method: Done parsing the mi tree. 
Jul  4 13:54:56 openser-pri openser[26899]: DEBUG: mi_xmlrpc: default_method: Done running the mi command. 
Jul  4 13:54:56 openser-pri openser[26899]: DEBUG: mi_xmlrpc: default_method: Done building response. 
Jul  4 13:54:56 openser-pri openser[26900]: DEBUG: mi_xmlrpc: default_method: starting up..... 
Jul  4 13:54:56 openser-pri openser[26900]: DEBUG: mi_xmlrpc: default_method: Done looking the mi command. 
Jul  4 13:54:56 openser-pri openser[26900]: DEBUG: mi_xmlrpc: default_method: Done parsing the mi tree. 
Jul  4 13:54:56 openser-pri openser[26900]: DEBUG: mi_xmlrpc: default_method: Done running the mi command. 
Jul  4 13:54:56 openser-pri openser[26900]: DEBUG: mi_xmlrpc: xr_build_response: Command processing failure: AOR not found 
Jul  4 13:54:56 openser-pri openser[26901]: DEBUG: mi_xmlrpc: default_method: starting up..... 
Jul  4 13:54:56 openser-pri openser[26901]: DEBUG: mi_xmlrpc: default_method: Done looking the mi command. 
Jul  4 13:54:56 openser-pri openser[26901]: DEBUG: mi_xmlrpc: default_method: Done parsing the mi tree. 
Jul  4 13:54:56 openser-pri openser[26901]: DEBUG: mi_xmlrpc: default_method: Done running the mi command. 
Jul  4 13:54:56 openser-pri openser[26901]: DEBUG: mi_xmlrpc: xr_build_response: Command processing failure: AOR not found 
Jul  4 13:54:56 openser-pri openser[26902]: DEBUG: mi_xmlrpc: default_method: starting up..... 
Jul  4 13:54:56 openser-pri openser[26902]: DEBUG: mi_xmlrpc: default_method: Done looking the mi command. 
Jul  4 13:54:56 openser-pri openser[26902]: DEBUG: mi_xmlrpc: default_method: Done parsing the mi tree. 
Jul  4 13:54:56 openser-pri openser[26902]: DEBUG: mi_xmlrpc: default_method: Done running the mi command. 
Jul  4 13:54:56 openser-pri openser[26902]: DEBUG: mi_xmlrpc: xr_build_response: Command processing failure: AOR not found 
Jul  4 14:04:28 openser-pri openser[26017]: SIP Request: 
Jul  4 14:04:28 openser-pri openser[26017]:  method:  <INVITE> 
Jul  4 14:04:28 openser-pri openser[26017]:  uri:     <sip:0615196262@barik.com> 
Jul  4 14:04:28 openser-pri openser[26017]:  version: <SIP/2.0> 
Jul  4 14:04:28 openser-pri openser[26017]: parse_headers: flags=2 
Jul  4 14:04:28 openser-pri openser[26017]: Found param type 232, <branch> = <z9hG4bKbbacd6944071b08fb>; state=16 
Jul  4 14:04:28 openser-pri openser[26017]: end of header reached, state=5 
Jul  4 14:04:28 openser-pri openser[26017]: parse_headers: Via found, flags=2 
Jul  4 14:04:28 openser-pri openser[26017]: parse_headers: this is the first via 
Jul  4 14:04:28 openser-pri openser[26017]: After parse_msg... 
Jul  4 14:04:28 openser-pri openser[26017]: preparing to run routing scripts... 
Jul  4 14:04:28 openser-pri openser[26017]: parse_headers: flags=10 
Jul  4 14:04:28 openser-pri openser[26017]: DEBUG: add_param: tag=339ca97a42 
Jul  4 14:04:28 openser-pri openser[26017]: DEBUG:parse_to:end of header reached, state=29 
Jul  4 14:04:28 openser-pri openser[26017]: DBUG:parse_to: display={Arturo}, ruri={sip:104@barik.com} 
Jul  4 14:04:28 openser-pri openser[26017]: OPENSER_NAME: 108 INVITE sip:104@barik.com -> sip:0615196262@barik.com status not listed 
Jul  4 14:04:28 openser-pri openser[26017]: OPENSER_NAME: 108 INVITE sip:0615196262@barik.com SIP/2.0^M Via: SIP/2.0/UDP 192.168.100.125:5060;branch=z9hG4bKbbacd6944071b08fb^M Max-Forwards: 70^M From: Arturo <sip:104@barik.com>;tag=339ca97a42^M To: 0615196262 <sip:0615196262@barik.com>^M Call-ID: 7e873a6807f32663^M CSeq: 28915 INVITE^M Allow:  INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK, SUBSCRIBE, INFO^M Allow-Events: talk, hold, conference^M Contact: Arturo <sip:104@192.168.100.125:5060;transport=udp>^M Supported: timer, 100rel, replaces^M User-Agent: Aastra 57i/2.1.0.2141^M Content-Type: application/sdp^M Content-Length: 288^M ^M v=0^M o=MxSIP 0 0 IN IP4 192.168.100.125^M s=SIP Call^M c=IN IP4 192.168.100.125^M t=0 0^M m=audio 3000 RTP/AVP 0 8 18 101^M a=rtpmap:0 PCMU/8000^M a=rtpmap:8 PCMA/8000^M a=rtpmap:18 G729/8000^M a=rtpmap:101 telephone-event/8000^M a=silenceSupp:on - - - -^M a=fmtp:101 0-15^M a=ptime:30^M a=sendrecv^M  
Jul  4 14:04:28 openser-pri openser[26017]: DEBUG:maxfwd:is_maxfwd_present: value = 70  
Jul  4 14:04:28 openser-pri openser[26017]: parse_headers: flags=200 
Jul  4 14:04:28 openser-pri openser[26017]: DEBUG:parse_to:end of header reached, state=10 
Jul  4 14:04:28 openser-pri openser[26017]: DBUG:parse_to: display={0615196262}, ruri={sip:0615196262@barik.com} 
Jul  4 14:04:28 openser-pri openser[26017]: DEBUG: get_hdr_field: <To> [39]; uri=[sip:0615196262@barik.com]  
Jul  4 14:04:28 openser-pri openser[26017]: DEBUG: to body [0615196262 <sip:0615196262@barik.com>^M ] 
Jul  4 14:04:28 openser-pri openser[26017]: get_hdr_field: cseq <CSeq>: <28915> <INVITE> 
Jul  4 14:04:28 openser-pri openser[26017]: DEBUG: get_hdr_body : content_length=288 
Jul  4 14:04:28 openser-pri openser[26017]: found end of header 
Jul  4 14:04:28 openser-pri openser[26017]: find_first_route: No Route headers found 
Jul  4 14:04:28 openser-pri openser[26017]: loose_route: There is no Route HF 
Jul  4 14:04:28 openser-pri openser[26017]: ### ROUTE 3 ENTRA 
Jul  4 14:04:28 openser-pri openser[26017]: #### ENTRA EN ALIASES 
Jul  4 14:04:28 openser-pri openser[26017]: lookup(): '0615196262@barik.com' Not found in usrloc 
Jul  4 14:04:28 openser-pri openser[26017]: #### SALE DE ALIASES 
Jul  4 14:04:28 openser-pri openser[26017]: ####### GATEWAY 
Jul  4 14:04:28 openser-pri openser[26017]: Proxy auth barik.com  destination:  <null>
Jul  4 14:04:28 openser-pri openser[26017]: parse_headers: flags=10000 
Jul  4 14:04:28 openser-pri openser[26017]: pre_auth(): Credentials with given realm not found 
Jul  4 14:04:28 openser-pri openser[26017]: build_auth_hf(): 'Proxy-Authenticate: Digest realm="barik.com", nonce="468b8df802b2bf130419f00dc437f4309dec9632"^M ' 
Jul  4 14:04:28 openser-pri openser[26017]: parse_headers: flags=ffffffffffffffff 
Jul  4 14:04:28 openser-pri openser[26017]: check_via_address(192.168.100.125, 192.168.100.125, 0) 
Jul  4 14:04:28 openser-pri openser[26017]: DEBUG:destroy_avp_list: destroying list 0xb56dc0a8 
Jul  4 14:04:28 openser-pri openser[26017]: receive_msg: cleaning up 
Jul  4 14:04:28 openser-pri openser[26014]: SIP Request: 
Jul  4 14:04:28 openser-pri openser[26014]:  method:  <ACK> 
Jul  4 14:04:29 openser-pri openser[26014]:  uri:     <sip:0615196262@barik.com> 
Jul  4 14:04:29 openser-pri openser[26014]:  version: <SIP/2.0> 
Jul  4 14:04:29 openser-pri openser[26014]: parse_headers: flags=2 
Jul  4 14:04:29 openser-pri openser[26014]: Found param type 232, <branch> = <z9hG4bKbbacd6944071b08fb>; state=16 
Jul  4 14:04:29 openser-pri openser[26014]: end of header reached, state=5 
Jul  4 14:04:29 openser-pri openser[26014]: parse_headers: Via found, flags=2 
Jul  4 14:04:29 openser-pri openser[26014]: parse_headers: this is the first via 
Jul  4 14:04:29 openser-pri openser[26014]: After parse_msg... 
Jul  4 14:04:29 openser-pri openser[26014]: preparing to run routing scripts... 
Jul  4 14:04:29 openser-pri openser[26014]: parse_headers: flags=8 
Jul  4 14:04:29 openser-pri openser[26014]: DEBUG: add_param: tag=ae7ac13e45ec2462651fb40fd57538a1.1aea 
Jul  4 14:04:29 openser-pri openser[26014]: DEBUG:parse_to:end of header reached, state=29 
Jul  4 14:04:29 openser-pri openser[26014]: DBUG:parse_to: display={0615196262}, ruri={sip:0615196262@barik.com} 
Jul  4 14:04:29 openser-pri openser[26014]: DEBUG: get_hdr_field: <To> [81]; uri=[sip:0615196262@barik.com]  
Jul  4 14:04:29 openser-pri openser[26014]: DEBUG: to body [0615196262 <sip:0615196262@barik.com>] 
Jul  4 14:04:29 openser-pri openser[26014]: DEBUG: sl_filter_ACK : local ACK found -> dropping it! 
Jul  4 14:04:29 openser-pri openser[26014]: DEBUG:destroy_avp_list: destroying list (nil) 
Jul  4 14:04:29 openser-pri openser[26014]: receive_msg: cleaning up 
Jul  4 14:04:29 openser-pri openser[26011]: SIP Request: 
Jul  4 14:04:29 openser-pri openser[26011]:  method:  <INVITE> 
Jul  4 14:04:29 openser-pri openser[26011]:  uri:     <sip:0615196262@barik.com> 
Jul  4 14:04:29 openser-pri openser[26011]:  version: <SIP/2.0> 
Jul  4 14:04:29 openser-pri openser[26011]: parse_headers: flags=2 
Jul  4 14:04:29 openser-pri openser[26011]: Found param type 232, <branch> = <z9hG4bKb3a02aab92ad002ba>; state=16 
Jul  4 14:04:29 openser-pri openser[26011]: end of header reached, state=5 
Jul  4 14:04:29 openser-pri openser[26011]: parse_headers: Via found, flags=2 
Jul  4 14:04:29 openser-pri openser[26011]: parse_headers: this is the first via 
Jul  4 14:04:29 openser-pri openser[26011]: After parse_msg... 
Jul  4 14:04:29 openser-pri openser[26011]: preparing to run routing scripts... 
Jul  4 14:04:29 openser-pri openser[26011]: parse_headers: flags=10 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG: add_param: tag=339ca97a42 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG:parse_to:end of header reached, state=29 
Jul  4 14:04:29 openser-pri openser[26011]: DBUG:parse_to: display={Arturo}, ruri={sip:104@barik.com} 
Jul  4 14:04:29 openser-pri openser[26011]: OPENSER_NAME: 106 INVITE sip:104@barik.com -> sip:0615196262@barik.com status not listed 
Jul  4 14:04:29 openser-pri openser[26011]: OPENSER_NAME: 106 INVITE sip:0615196262@barik.com SIP/2.0^M Via: SIP/2.0/UDP 192.168.100.125:5060;branch=z9hG4bKb3a02aab92ad002ba^M Proxy-Authorization: Digest username="104",realm="barik.com",nonce="468b8df802b2bf130419f00dc437f4309dec9632",uri="sip:0615196262@barik.com",response="67492f91aa65f0fcbb8140f810aa034a"^M Max-Forwards: 70^M From: Arturo <sip:104@barik.com>;tag=339ca97a42^M To: 0615196262 <sip:0615196262@barik.com>^M Call-ID: 7e873a6807f32663^M CSeq: 28916 INVITE^M Allow:  INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK, SUBSCRIBE, INFO^M Allow-Events: talk, hold, conference^M Contact: Arturo <sip:104@192.168.100.125:5060;transport=udp>^M Supported: timer, 100rel, replaces^M User-Agent: Aastra 57i/2.1.0.2141^M Content-Type: application/sdp^M Content-Length: 288^M ^M v=0^M o=MxSIP 0 0 IN IP4 192.168.100.125^M s=SIP Call^M c=IN IP4 192.168.100.125^M t=0 0^M m=audio 3000 RTP/AVP 0 8 18 101^M a=rtpmap:0 PCMU/8000^M a=rtpmap:8 PCMA/8000^M a=rtpmap:18 G7
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG:maxfwd:is_maxfwd_present: value = 70  
Jul  4 14:04:29 openser-pri openser[26011]: parse_headers: flags=200 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG:parse_to:end of header reached, state=10 
Jul  4 14:04:29 openser-pri openser[26011]: DBUG:parse_to: display={0615196262}, ruri={sip:0615196262@barik.com} 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG: get_hdr_field: <To> [39]; uri=[sip:0615196262@barik.com]  
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG: to body [0615196262 <sip:0615196262@barik.com>^M ] 
Jul  4 14:04:29 openser-pri openser[26011]: get_hdr_field: cseq <CSeq>: <28916> <INVITE> 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG: get_hdr_body : content_length=288 
Jul  4 14:04:29 openser-pri openser[26011]: found end of header 
Jul  4 14:04:29 openser-pri openser[26011]: find_first_route: No Route headers found 
Jul  4 14:04:29 openser-pri openser[26011]: loose_route: There is no Route HF 
Jul  4 14:04:29 openser-pri openser[26011]: ### ROUTE 3 ENTRA 
Jul  4 14:04:29 openser-pri openser[26011]: #### ENTRA EN ALIASES 
Jul  4 14:04:29 openser-pri openser[26011]: lookup(): '0615196262@barik.com' Not found in usrloc 
Jul  4 14:04:29 openser-pri openser[26011]: #### SALE DE ALIASES 
Jul  4 14:04:29 openser-pri openser[26011]: ####### GATEWAY 
Jul  4 14:04:29 openser-pri openser[26011]: Proxy auth barik.com  destination:  <null>
Jul  4 14:04:29 openser-pri openser[26011]: check_nonce(): comparing [468b8df802b2bf130419f00dc437f4309dec9632] and [468b8df802b2bf130419f00dc437f4309dec9632] 
Jul  4 14:04:29 openser-pri openser[26011]: HA1 string calculated: a82436e751d294d84ef44a51a6bfeec5 
Jul  4 14:04:29 openser-pri openser[26011]: check_response(): Our result = '67492f91aa65f0fcbb8140f810aa034a' 
Jul  4 14:04:29 openser-pri openser[26011]: check_response(): Authorization is OK 
Jul  4 14:04:29 openser-pri openser[26011]: generate_avps: set string AVP "rpid"/0 = "aaa" 
Jul  4 14:04:29 openser-pri openser[26011]: check_username(): Digest username and URI username match 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG:lcr:load_gws: add matched_gws[0]=[0,0] 
Jul  4 14:04:29 openser-pri openser[26011]: load_gws(): DEBUG: Added gw_uri_avp <sip:|0@192.168.222.201:5060;transport=udp> 
Jul  4 14:04:29 openser-pri openser[26011]: load_gws(): DEBUG: Added ruri_user_avp <0615196262> 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG: t_newtran:  T on entrance=0xffffffff 
Jul  4 14:04:29 openser-pri openser[26011]: parse_headers: flags=ffffffffffffffff 
Jul  4 14:04:29 openser-pri openser[26011]: parse_headers: flags=78 
Jul  4 14:04:29 openser-pri openser[26011]: t_lookup_request: start searching: hash=20284, isACK=0 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG: RFC3261 transaction matching failed 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG: t_lookup_request: no transaction found 
Jul  4 14:04:29 openser-pri openser[26011]: DBG: trans=0xb56dc0f8, callback type 1, id 1 entered 
Jul  4 14:04:29 openser-pri openser[26011]: DBG: trans=0xb56dc0f8, callback type 1, id 0 entered 
Jul  4 14:04:29 openser-pri openser[26011]: parse_headers: flags=78 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG: noisy_timer set for accounting 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG:rr:is_direction: param ftag not found 
Jul  4 14:04:29 openser-pri openser[26011]: parse_headers: flags=ffffffffffffffff 
Jul  4 14:04:29 openser-pri openser[26011]: check_via_address(192.168.100.125, 192.168.100.125, 0) 
Jul  4 14:04:29 openser-pri openser[26011]: WARNING:vqm_resize: resize(0) called 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG:tm:_reply_light: reply sent out. buf=0x819e580: SIP/2.0 1..., shmem=0xb56ddd28: SIP/2.0 1 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG:tm:_reply_light: finished 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG: mk_proxy: doing DNS lookup... 
Jul  4 14:04:29 openser-pri openser[26011]: check_via_address(192.168.100.125, 192.168.100.125, 0) 
Jul  4 14:04:29 openser-pri openser[26011]: DBG:check_against_rule_list: using list dns  
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG:tm:set_timer: relative timeout is 500000 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG: add_to_tail_of_timer[4]: 0xb56dc244 (8239900000) 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG:tm:set_timer: relative timeout is 10 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG: add_to_tail_of_timer[0]: 0xb56dc260 (8249) 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG:tm:t_relay_to: new transaction fwd'ed 
Jul  4 14:04:29 openser-pri openser[26011]: ### ROUTE 3 SALE 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG:tm:UNREF_UNSAFE: after is 0 
Jul  4 14:04:29 openser-pri openser[26011]: DEBUG:destroy_avp_list: destroying list (nil) 
Jul  4 14:04:29 openser-pri openser[26011]: receive_msg: cleaning up 
Jul  4 14:04:29 openser-pri openser[26016]: SIP Reply  (status): 
Jul  4 14:04:29 openser-pri openser[26016]:  version: <SIP/2.0> 
Jul  4 14:04:29 openser-pri openser[26016]:  status:  <100> 
Jul  4 14:04:29 openser-pri openser[26016]:  reason:  <Trying> 
Jul  4 14:04:29 openser-pri openser[26016]: parse_headers: flags=2 
Jul  4 14:04:29 openser-pri openser[26016]: Found param type 232, <branch> = <z9hG4bKc3f4.5a795ab6.0>; state=9 
Jul  4 14:04:29 openser-pri openser[26016]: parse_via: next_via 
Jul  4 14:04:29 openser-pri openser[26016]: Found param type 232, <branch> = <z9hG4bKb3a02aab92ad002ba>; state=16 
Jul  4 14:04:29 openser-pri openser[26016]: end of header reached, state=5 
Jul  4 14:04:29 openser-pri openser[26016]: parse_headers: Via found, flags=2 
Jul  4 14:04:29 openser-pri openser[26016]: parse_headers: this is the first via 
Jul  4 14:04:29 openser-pri openser[26016]: After parse_msg... 
Jul  4 14:04:29 openser-pri openser[26016]: DEBUG:forward_reply: found module tm, passing reply to it 
Jul  4 14:04:29 openser-pri openser[26016]: DEBUG: t_check: start=0xffffffff 
Jul  4 14:04:29 openser-pri openser[26016]: parse_headers: flags=22 
Jul  4 14:04:29 openser-pri openser[26016]: DEBUG: add_param: tag=D2C738-17AF 
Jul  4 14:04:29 openser-pri openser[26016]: DEBUG:parse_to:end of header reached, state=29 
Jul  4 14:04:29 openser-pri openser[26016]: DBUG:parse_to: display={0615196262}, ruri={sip:0615196262@barik.com} 
Jul  4 14:04:29 openser-pri openser[26016]: DEBUG: get_hdr_field: <To> [55]; uri=[sip:0615196262@barik.com]  
Jul  4 14:04:29 openser-pri openser[26016]: DEBUG: to body [0615196262 <sip:0615196262@barik.com>] 
Jul  4 14:04:29 openser-pri openser[26016]: get_hdr_field: cseq <CSeq>: <28916> <INVITE> 
Jul  4 14:04:29 openser-pri openser[26016]: parse_headers: flags=8 
Jul  4 14:04:29 openser-pri openser[26016]: DEBUG: t_reply_matching: hash 20284 label 1806014373 branch 0 
Jul  4 14:04:29 openser-pri openser[26016]: DEBUG:tm:REF_UNSAFE: after is 1 
Jul  4 14:04:29 openser-pri openser[26016]: DEBUG: t_reply_matching: reply matched (T=0xb56dc0f8)! 
Jul  4 14:04:29 openser-pri openser[26016]: DBG: trans=0xb56dc0f8, callback type 2, id 0 entered 
Jul  4 14:04:29 openser-pri openser[26016]: DEBUG: t_check: end=0xb56dc0f8 
Jul  4 14:04:29 openser-pri openser[26016]: DEBUG:tm:reply_received: org. status uas=100, uac[0]=0 local=0 is_invite=1) 
Jul  4 14:04:29 openser-pri openser[26016]: DEBUG:tm:t_should_relay_response: T_code=100, new_code=100 
Jul  4 14:04:29 openser-pri openser[26016]: DEBUG:tm:relay_reply: branch=0, save=0, relay=-1 
Jul  4 14:04:29 openser-pri openser[26016]: DEBUG:tm:set_timer: relative timeout is 27 
Jul  4 14:04:29 openser-pri openser[26016]: DEBUG: add_to_tail_of_timer[1]: 0xb56dc260 (8266) 
Jul  4 14:04:29 openser-pri openser[26016]: DEBUG:tm:UNREF_UNSAFE: after is 0 
Jul  4 14:04:29 openser-pri openser[26016]: DEBUG:destroy_avp_list: destroying list (nil) 
Jul  4 14:04:29 openser-pri openser[26016]: receive_msg: cleaning up 
Jul  4 14:04:29 openser-pri openser[26018]: DEBUG: timer routine:4,tl=0xb56dc244 next=(nil), timeout=8239900000 
Jul  4 14:04:34 openser-pri openser[26013]: SIP Reply  (status): 
Jul  4 14:04:34 openser-pri openser[26013]:  version: <SIP/2.0> 
Jul  4 14:04:34 openser-pri openser[26013]:  status:  <183> 
Jul  4 14:04:34 openser-pri openser[26013]:  reason:  <Session Progress> 
Jul  4 14:04:34 openser-pri openser[26013]: parse_headers: flags=2 
Jul  4 14:04:34 openser-pri openser[26013]: Found param type 232, <branch> = <z9hG4bKc3f4.5a795ab6.0>; state=9 
Jul  4 14:04:34 openser-pri openser[26013]: parse_via: next_via 
Jul  4 14:04:34 openser-pri openser[26013]: Found param type 232, <branch> = <z9hG4bKb3a02aab92ad002ba>; state=16 
Jul  4 14:04:34 openser-pri openser[26013]: end of header reached, state=5 
Jul  4 14:04:34 openser-pri openser[26013]: parse_headers: Via found, flags=2 
Jul  4 14:04:34 openser-pri openser[26013]: parse_headers: this is the first via 
Jul  4 14:04:34 openser-pri openser[26013]: After parse_msg... 
Jul  4 14:04:34 openser-pri openser[26013]: DEBUG:forward_reply: found module tm, passing reply to it 
Jul  4 14:04:34 openser-pri openser[26013]: DEBUG: t_check: start=0xffffffff 
Jul  4 14:04:34 openser-pri openser[26013]: parse_headers: flags=22 
Jul  4 14:04:34 openser-pri openser[26013]: DEBUG: add_param: tag=D2C738-17AF 
Jul  4 14:04:34 openser-pri openser[26013]: DEBUG:parse_to:end of header reached, state=29 
Jul  4 14:04:34 openser-pri openser[26013]: DBUG:parse_to: display={0615196262}, ruri={sip:0615196262@barik.com} 
Jul  4 14:04:34 openser-pri openser[26013]: DEBUG: get_hdr_field: <To> [55]; uri=[sip:0615196262@barik.com]  
Jul  4 14:04:34 openser-pri openser[26013]: DEBUG: to body [0615196262 <sip:0615196262@barik.com>] 
Jul  4 14:04:34 openser-pri openser[26013]: get_hdr_field: cseq <CSeq>: <28916> <INVITE> 
Jul  4 14:04:34 openser-pri openser[26013]: parse_headers: flags=8 
Jul  4 14:04:34 openser-pri openser[26013]: DEBUG: t_reply_matching: hash 20284 label 1806014373 branch 0 
Jul  4 14:04:34 openser-pri openser[26013]: DEBUG:tm:REF_UNSAFE: after is 1 
Jul  4 14:04:34 openser-pri openser[26013]: DEBUG: t_reply_matching: reply matched (T=0xb56dc0f8)! 
Jul  4 14:04:34 openser-pri openser[26013]: DBG: trans=0xb56dc0f8, callback type 2, id 0 entered 
Jul  4 14:04:34 openser-pri openser[26013]: DEBUG: t_check: end=0xb56dc0f8 
Jul  4 14:04:34 openser-pri openser[26013]: DEBUG:tm:reply_received: org. status uas=100, uac[0]=100 local=0 is_invite=1) 
Jul  4 14:04:34 openser-pri openser[26013]: DEBUG:tm:t_should_relay_response: T_code=100, new_code=183 
Jul  4 14:04:34 openser-pri openser[26013]: DEBUG:tm:relay_reply: branch=0, save=0, relay=0 
Jul  4 14:04:34 openser-pri openser[26013]:  old size: 971, new size: 915 
Jul  4 14:04:34 openser-pri openser[26013]: build_res_from_sip_res: copied size: orig:91, new: 35, rest: 880 msg= SIP/2.0 183 Session Progress^M Via: SIP/2.0/UDP 192.168.100.125:5060;branch=z9hG4bKb3a02aab92ad002ba^M From: Arturo <sip:104@barik.com>;tag=339ca97a42^M To: 0615196262 <sip:0615196262@barik.com>;tag=D2C738-17AF^M Date: Wed, 04 Jul 2007 10:07:49 GMT^M Call-ID: 7e873a6807f32663^M Server: Cisco-SIPGateway/IOS-12.x^M CSeq: 28916 INVITE^M Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER^M Require: 100rel^M RSeq: 2331^M Allow-Events: telephone-event^M Contact: <sip:0615196262@192.168.222.201:5060>^M Record-Route: <sip:192.168.1.129;lr=on;ftag=339ca97a42>^M Content-Type: application/sdp^M Content-Disposition: session;handling=required^M Content-Length: 221^M ^M v=0^M o=CiscoSystemsSIP-GW-UserAgent 7626 7311 IN IP4 192.168.222.201^M s=SIP Call^M c=IN IP4 192.168.222.201^M t=0 0^M m=audio 18962 RTP/AVP 0^M c=IN IP4 192.168.222.201^M a=rtpmap:0 PCMU/8000^M a=ptime:20^M
Jul  4 14:04:34 openser-pri openser[26013]: DEBUG:tm:relay_reply: sent buf=0x819e988: SIP/2.0 1..., shmem=0xb56e0450: SIP/2.0 1 
Jul  4 14:04:34 openser-pri openser[26013]: DBG: trans=0xb56dc0f8, callback type 128, id 0 entered 
Jul  4 14:04:34 openser-pri openser[26013]: DEBUG:tm:set_timer: relative timeout is 27 
Jul  4 14:04:34 openser-pri openser[26013]: DEBUG: add_to_tail_of_timer[1]: 0xb56dc260 (8271) 
Jul  4 14:04:34 openser-pri openser[26013]: DEBUG:tm:UNREF_UNSAFE: after is 0 
Jul  4 14:04:34 openser-pri openser[26013]: DEBUG:destroy_avp_list: destroying list (nil) 
Jul  4 14:04:34 openser-pri openser[26013]: receive_msg: cleaning up 
Jul  4 14:04:34 openser-pri openser[26014]: SIP Request: 
Jul  4 14:04:34 openser-pri openser[26014]:  method:  <PRACK> 
Jul  4 14:04:34 openser-pri openser[26014]:  uri:     <sip:0615196262@192.168.222.201:5060> 
Jul  4 14:04:34 openser-pri openser[26014]:  version: <SIP/2.0> 
Jul  4 14:04:34 openser-pri openser[26014]: parse_headers: flags=2 
Jul  4 14:04:34 openser-pri openser[26014]: Found param type 232, <branch> = <z9hG4bK7649b1cad9fb3844d>; state=16 
Jul  4 14:04:34 openser-pri openser[26014]: end of header reached, state=5 
Jul  4 14:04:34 openser-pri openser[26014]: parse_headers: Via found, flags=2 
Jul  4 14:04:34 openser-pri openser[26014]: parse_headers: this is the first via 
Jul  4 14:04:34 openser-pri openser[26014]: After parse_msg... 
Jul  4 14:04:34 openser-pri openser[26014]: preparing to run routing scripts... 
Jul  4 14:04:34 openser-pri openser[26014]: parse_headers: flags=10 
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG: add_param: tag=339ca97a42 
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG:parse_to:end of header reached, state=29 
Jul  4 14:04:34 openser-pri openser[26014]: DBUG:parse_to: display={Arturo}, ruri={sip:104@barik.com} 
Jul  4 14:04:34 openser-pri openser[26014]: OPENSER_NAME: 91 PRACK sip:104@barik.com -> sip:0615196262@192.168.222.201:5060 status not listed 
Jul  4 14:04:34 openser-pri openser[26014]: OPENSER_NAME: 91 PRACK sip:0615196262@192.168.222.201:5060 SIP/2.0^M Via: SIP/2.0/UDP 192.168.100.125:5060;branch=z9hG4bK7649b1cad9fb3844d^M Route: <sip:192.168.1.129;lr=on;ftag=339ca97a42>^M Proxy-Authorization: Digest username="104",realm="barik.com",nonce="468b8df802b2bf130419f00dc437f4309dec9632",uri="sip:0615196262@192.168.222.201:5060",response="4848362cade3573eb1efd8e2a2c342cb"^M Max-Forwards: 70^M From: Arturo <sip:104@barik.com>;tag=339ca97a42^M To: 0615196262 <sip:0615196262@barik.com>;tag=D2C738-17AF^M Call-ID: 7e873a6807f32663^M CSeq: 28917 PRACK^M Allow:  INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK, SUBSCRIBE, INFO^M Allow-Events: talk, hold, conference^M RAck: 2331 28916 INVITE^M Supported: timer^M User-Agent: Aastra 57i/2.1.0.2141^M Content-Length: 0^M ^M  
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG:maxfwd:is_maxfwd_present: value = 70  
Jul  4 14:04:34 openser-pri openser[26014]: parse_headers: flags=200 
Jul  4 14:04:34 openser-pri openser[26014]: parse_headers: flags=8 
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG: add_param: tag=D2C738-17AF 
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG:parse_to:end of header reached, state=29 
Jul  4 14:04:34 openser-pri openser[26014]: DBUG:parse_to: display={0615196262}, ruri={sip:0615196262@barik.com} 
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG: get_hdr_field: <To> [55]; uri=[sip:0615196262@barik.com]  
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG: to body [0615196262 <sip:0615196262@barik.com>] 
Jul  4 14:04:34 openser-pri openser[26014]: is_preloaded: No 
Jul  4 14:04:34 openser-pri openser[26014]: grep_sock_info - checking if host==us: 15==13 &&  [192.168.222.201] == [192.168.1.129] 
Jul  4 14:04:34 openser-pri openser[26014]: grep_sock_info - checking if port 5060 matches port 5060 
Jul  4 14:04:34 openser-pri openser[26014]: grep_sock_info - checking if host==us: 15==13 &&  [192.168.222.201] == [192.168.1.129] 
Jul  4 14:04:34 openser-pri openser[26014]: grep_sock_info - checking if port 5060 matches port 5060 
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG:check_self: host != me 
Jul  4 14:04:34 openser-pri openser[26014]: grep_sock_info - checking if host==us: 13==13 &&  [192.168.1.129] == [192.168.1.129] 
Jul  4 14:04:34 openser-pri openser[26014]: grep_sock_info - checking if port 5060 matches port 5060 
Jul  4 14:04:34 openser-pri openser[26014]: after_loose: Topmost route URI: 'sip:192.168.1.129;lr=on;ftag=339ca97a42' is me 
Jul  4 14:04:34 openser-pri openser[26014]: parse_headers: flags=200 
Jul  4 14:04:34 openser-pri openser[26014]: get_hdr_field: cseq <CSeq>: <28917> <PRACK> 
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG: get_hdr_body : content_length=0 
Jul  4 14:04:34 openser-pri openser[26014]: found end of header 
Jul  4 14:04:34 openser-pri openser[26014]: find_next_route: No next Route HF found 
Jul  4 14:04:34 openser-pri openser[26014]: after_loose: No next URI found 
Jul  4 14:04:34 openser-pri openser[26014]: DBG:rr:run_rr_callbacks: callback id 0 entered with <lr=on;ftag=339ca97a42> 
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG:dialog:dlg_onroute: Route param 'did' not found 
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG: t_newtran:  T on entrance=0xffffffff 
Jul  4 14:04:34 openser-pri openser[26014]: parse_headers: flags=ffffffffffffffff 
Jul  4 14:04:34 openser-pri openser[26014]: parse_headers: flags=78 
Jul  4 14:04:34 openser-pri openser[26014]: t_lookup_request: start searching: hash=20285, isACK=0 
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG: RFC3261 transaction matching failed 
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG: t_lookup_request: no transaction found 
Jul  4 14:04:34 openser-pri openser[26014]: DBG: trans=0xb56de568, callback type 1, id 1 entered 
Jul  4 14:04:34 openser-pri openser[26014]: DBG: trans=0xb56de568, callback type 1, id 0 entered 
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG: mk_proxy: doing DNS lookup... 
Jul  4 14:04:34 openser-pri openser[26014]: check_via_address(192.168.100.125, 192.168.100.125, 0) 
Jul  4 14:04:34 openser-pri openser[26014]: DBG:check_against_rule_list: using list dns  
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG:tm:set_timer: relative timeout is 500000 
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG: add_to_tail_of_timer[4]: 0xb56de6b4 (8245400000) 
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG:tm:set_timer: relative timeout is 10 
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG: add_to_tail_of_timer[0]: 0xb56de6d0 (8254) 
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG:tm:t_relay_to: new transaction fwd'ed 
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG:tm:UNREF_UNSAFE: after is 0 
Jul  4 14:04:34 openser-pri openser[26014]: DEBUG:destroy_avp_list: destroying list (nil) 
Jul  4 14:04:34 openser-pri openser[26014]: receive_msg: cleaning up 
Jul  4 14:04:34 openser-pri openser[26012]: SIP Reply  (status): 
Jul  4 14:04:34 openser-pri openser[26012]:  version: <SIP/2.0> 
Jul  4 14:04:34 openser-pri openser[26012]:  status:  <200> 
Jul  4 14:04:34 openser-pri openser[26012]:  reason:  <OK> 
Jul  4 14:04:34 openser-pri openser[26012]: parse_headers: flags=2 
Jul  4 14:04:34 openser-pri openser[26012]: Found param type 232, <branch> = <z9hG4bKd3f4.06b7aa07.0>; state=9 
Jul  4 14:04:34 openser-pri openser[26012]: parse_via: next_via 
Jul  4 14:04:34 openser-pri openser[26012]: Found param type 232, <branch> = <z9hG4bK7649b1cad9fb3844d>; state=16 
Jul  4 14:04:34 openser-pri openser[26012]: end of header reached, state=5 
Jul  4 14:04:34 openser-pri openser[26012]: parse_headers: Via found, flags=2 
Jul  4 14:04:34 openser-pri openser[26012]: parse_headers: this is the first via 
Jul  4 14:04:34 openser-pri openser[26012]: After parse_msg... 
Jul  4 14:04:34 openser-pri openser[26012]: DEBUG:forward_reply: found module tm, passing reply to it 
Jul  4 14:04:34 openser-pri openser[26012]: DEBUG: t_check: start=0xffffffff 
Jul  4 14:04:34 openser-pri openser[26012]: parse_headers: flags=22 
Jul  4 14:04:34 openser-pri openser[26012]: DEBUG: add_param: tag=D2C738-17AF 
Jul  4 14:04:34 openser-pri openser[26012]: DEBUG:parse_to:end of header reached, state=29 
Jul  4 14:04:34 openser-pri openser[26012]: DBUG:parse_to: display={0615196262}, ruri={sip:0615196262@barik.com} 
Jul  4 14:04:34 openser-pri openser[26012]: DEBUG: get_hdr_field: <To> [55]; uri=[sip:0615196262@barik.com]  
Jul  4 14:04:34 openser-pri openser[26012]: DEBUG: to body [0615196262 <sip:0615196262@barik.com>] 
Jul  4 14:04:34 openser-pri openser[26012]: get_hdr_field: cseq <CSeq>: <28917> <PRACK> 
Jul  4 14:04:34 openser-pri openser[26012]: DEBUG: t_reply_matching: hash 20285 label 1890220896 branch 0 
Jul  4 14:04:34 openser-pri openser[26012]: DEBUG:tm:REF_UNSAFE: after is 1 
Jul  4 14:04:34 openser-pri openser[26012]: DEBUG: t_reply_matching: reply matched (T=0xb56de568)! 
Jul  4 14:04:34 openser-pri openser[26012]: DEBUG: t_check: end=0xb56de568 
Jul  4 14:04:34 openser-pri openser[26012]: DEBUG:tm:reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=0) 
Jul  4 14:04:34 openser-pri openser[26012]: DEBUG:tm:t_should_relay_response: T_code=0, new_code=200 
Jul  4 14:04:34 openser-pri openser[26012]: DEBUG:tm:relay_reply: branch=0, save=0, relay=0 
Jul  4 14:04:34 openser-pri openser[26012]:  old size: 390, new size: 334 
Jul  4 14:04:34 openser-pri openser[26012]: build_res_from_sip_res: copied size: orig:77, new: 21, rest: 313 msg= SIP/2.0 200 OK^M Via: SIP/2.0/UDP 192.168.100.125:5060;branch=z9hG4bK7649b1cad9fb3844d^M From: Arturo <sip:104@barik.com>;tag=339ca97a42^M To: 0615196262 <sip:0615196262@barik.com>;tag=D2C738-17AF^M Date: Wed, 04 Jul 2007 10:07:54 GMT^M Call-ID: 7e873a6807f32663^M Server: Cisco-SIPGateway/IOS-12.x^M CSeq: 28917 PRACK^M Content-Length: 0^M ^M  
Jul  4 14:04:34 openser-pri openser[26012]: WARNING:vqm_resize: resize(0) called 
Jul  4 14:04:34 openser-pri openser[26012]: DEBUG: add_to_tail_of_timer[2]: 0xb56de5b0 (8249) 
Jul  4 14:04:34 openser-pri openser[26012]: DEBUG:tm:relay_reply: sent buf=0x819e550: SIP/2.0 2..., shmem=0xb56ddd28: SIP/2.0 2 
Jul  4 14:04:34 openser-pri openser[26012]: DEBUG: cleanup_uac_timers: RETR/FR timers reset 
Jul  4 14:04:34 openser-pri openser[26012]: DEBUG:tm:UNREF_UNSAFE: after is 0 
Jul  4 14:04:34 openser-pri openser[26012]: DEBUG:destroy_avp_list: destroying list (nil) 
Jul  4 14:04:34 openser-pri openser[26012]: receive_msg: cleaning up 
Jul  4 14:04:35 openser-pri openser[26018]: DEBUG: timer routine:4,tl=0xb56de6b4 next=(nil), timeout=8245400000 
Jul  4 14:04:38 openser-pri openser[26018]: DEBUG: timer routine:2,tl=0xb56de5b0 next=(nil), timeout=8249 
Jul  4 14:04:38 openser-pri openser[26018]: DEBUG: wait_handler : removing 0xb56de568 from table  
Jul  4 14:04:38 openser-pri openser[26018]: DEBUG: delete transaction 0xb56de568 
Jul  4 14:04:38 openser-pri openser[26018]: DEBUG: wait_handler : done 
Jul  4 14:04:40 openser-pri openser[26016]: SIP Reply  (status): 
Jul  4 14:04:40 openser-pri openser[26016]:  version: <SIP/2.0> 
Jul  4 14:04:40 openser-pri openser[26016]:  status:  <200> 
Jul  4 14:04:40 openser-pri openser[26016]:  reason:  <OK> 
Jul  4 14:04:40 openser-pri openser[26016]: parse_headers: flags=2 
Jul  4 14:04:40 openser-pri openser[26016]: Found param type 232, <branch> = <z9hG4bKc3f4.5a795ab6.0>; state=9 
Jul  4 14:04:40 openser-pri openser[26016]: parse_via: next_via 
Jul  4 14:04:40 openser-pri openser[26016]: Found param type 232, <branch> = <z9hG4bKb3a02aab92ad002ba>; state=16 
Jul  4 14:04:40 openser-pri openser[26016]: end of header reached, state=5 
Jul  4 14:04:40 openser-pri openser[26016]: parse_headers: Via found, flags=2 
Jul  4 14:04:40 openser-pri openser[26016]: parse_headers: this is the first via 
Jul  4 14:04:40 openser-pri openser[26016]: After parse_msg... 
Jul  4 14:04:40 openser-pri openser[26016]: DEBUG:forward_reply: found module tm, passing reply to it 
Jul  4 14:04:40 openser-pri openser[26016]: DEBUG: t_check: start=0xffffffff 
Jul  4 14:04:40 openser-pri openser[26016]: parse_headers: flags=22 
Jul  4 14:04:40 openser-pri openser[26016]: DEBUG: add_param: tag=D2C738-17AF 
Jul  4 14:04:40 openser-pri openser[26016]: DEBUG:parse_to:end of header reached, state=29 
Jul  4 14:04:40 openser-pri openser[26016]: DBUG:parse_to: display={0615196262}, ruri={sip:0615196262@barik.com} 
Jul  4 14:04:40 openser-pri openser[26016]: DEBUG: get_hdr_field: <To> [55]; uri=[sip:0615196262@barik.com]  
Jul  4 14:04:40 openser-pri openser[26016]: DEBUG: to body [0615196262 <sip:0615196262@barik.com>] 
Jul  4 14:04:40 openser-pri openser[26016]: get_hdr_field: cseq <CSeq>: <28916> <INVITE> 
Jul  4 14:04:40 openser-pri openser[26016]: parse_headers: flags=8 
Jul  4 14:04:40 openser-pri openser[26016]: DEBUG: t_reply_matching: hash 20284 label 1806014373 branch 0 
Jul  4 14:04:40 openser-pri openser[26016]: DEBUG:tm:REF_UNSAFE: after is 1 
Jul  4 14:04:40 openser-pri openser[26016]: DEBUG: t_reply_matching: reply matched (T=0xb56dc0f8)! 
Jul  4 14:04:40 openser-pri openser[26016]: parse_headers: flags=8 
Jul  4 14:04:40 openser-pri openser[26016]: DBG: trans=0xb56dc0f8, callback type 2, id 0 entered 
Jul  4 14:04:40 openser-pri openser[26016]: parse_headers: flags=8 
Jul  4 14:04:40 openser-pri openser[26016]: DEBUG: t_check: end=0xb56dc0f8 
Jul  4 14:04:40 openser-pri openser[26016]: DEBUG:tm:reply_received: org. status uas=183, uac[0]=183 local=0 is_invite=1) 
Jul  4 14:04:40 openser-pri openser[26016]: DEBUG:tm:t_should_relay_response: T_code=183, new_code=200 
Jul  4 14:04:40 openser-pri openser[26016]: DEBUG:tm:relay_reply: branch=0, save=0, relay=0 
Jul  4 14:04:40 openser-pri openser[26016]:  old size: 928, new size: 872 
Jul  4 14:04:40 openser-pri openser[26016]: build_res_from_sip_res: copied size: orig:77, new: 21, rest: 851 msg= SIP/2.0 200 OK^M Via: SIP/2.0/UDP 192.168.100.125:5060;branch=z9hG4bKb3a02aab92ad002ba^M From: Arturo <sip:104@barik.com>;tag=339ca97a42^M To: 0615196262 <sip:0615196262@barik.com>;tag=D2C738-17AF^M Date: Wed, 04 Jul 2007 10:07:54 GMT^M Call-ID: 7e873a6807f32663^M Server: Cisco-SIPGateway/IOS-12.x^M CSeq: 28916 INVITE^M Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER^M Allow-Events: telephone-event^M Contact: <sip:0615196262@192.168.222.201:5060>^M Record-Route: <sip:192.168.1.129;lr=on;ftag=339ca97a42>^M Content-Type: application/sdp^M Content-Disposition: session;handling=required^M Content-Length: 221^M ^M v=0^M o=CiscoSystemsSIP-GW-UserAgent 7626 7311 IN IP4 192.168.222.201^M s=SIP Call^M c=IN IP4 192.168.222.201^M t=0 0^M m=audio 18962 RTP/AVP 0^M c=IN IP4 192.168.222.201^M a=rtpmap:0 PCMU/8000^M a=ptime:20^M a=direction:passive^M  
Jul  4 14:04:40 openser-pri openser[26016]: DEBUG: update_totag_set: new totag  
Jul  4 14:04:40 openser-pri openser[26016]: DEBUG: add_to_tail_of_timer[2]: 0xb56dc140 (8255) 
Jul  4 14:04:40 openser-pri openser[26016]: DEBUG:tm:relay_reply: sent buf=0x819e2e8: SIP/2.0 2..., shmem=0xb56e0450: SIP/2.0 2 
Jul  4 14:04:40 openser-pri openser[26016]: DBG: trans=0xb56dc0f8, callback type 128, id 0 entered 
Jul  4 14:04:40 openser-pri openser[26016]: --++legs2strar: beginning with start=1, msg->id=106 
Jul  4 14:04:41 openser-pri openser[26013]: SIP Request: 
Jul  4 14:04:41 openser-pri openser[26013]:  method:  <ACK> 
Jul  4 14:04:41 openser-pri openser[26013]:  uri:     <sip:0615196262@192.168.222.201:5060> 
Jul  4 14:04:41 openser-pri openser[26013]:  version: <SIP/2.0> 
Jul  4 14:04:41 openser-pri openser[26013]: parse_headers: flags=2 
Jul  4 14:04:41 openser-pri openser[26013]: Found param type 232, <branch> = <z9hG4bKc359e02551e314103>; state=16 
Jul  4 14:04:41 openser-pri openser[26013]: end of header reached, state=5 
Jul  4 14:04:41 openser-pri openser[26013]: parse_headers: Via found, flags=2 
Jul  4 14:04:41 openser-pri openser[26013]: parse_headers: this is the first via 
Jul  4 14:04:41 openser-pri openser[26013]: After parse_msg... 
Jul  4 14:04:41 openser-pri openser[26013]: preparing to run routing scripts... 
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG : sl_filter_ACK: to late to be a local ACK! 
Jul  4 14:04:41 openser-pri openser[26013]: parse_headers: flags=100 
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG:maxfwd:is_maxfwd_present: value = 70  
Jul  4 14:04:41 openser-pri openser[26013]: parse_headers: flags=10 
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG: add_param: tag=339ca97a42 
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG:parse_to:end of header reached, state=29 
Jul  4 14:04:41 openser-pri openser[26013]: DBUG:parse_to: display={Arturo}, ruri={sip:104@barik.com} 
Jul  4 14:04:41 openser-pri openser[26013]: parse_headers: flags=200 
Jul  4 14:04:41 openser-pri openser[26013]: parse_headers: flags=8 
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG: add_param: tag=D2C738-17AF 
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG:parse_to:end of header reached, state=29 
Jul  4 14:04:41 openser-pri openser[26013]: DBUG:parse_to: display={0615196262}, ruri={sip:0615196262@barik.com} 
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG: get_hdr_field: <To> [55]; uri=[sip:0615196262@barik.com]  
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG: to body [0615196262 <sip:0615196262@barik.com>] 
Jul  4 14:04:41 openser-pri openser[26013]: is_preloaded: No 
Jul  4 14:04:41 openser-pri openser[26013]: grep_sock_info - checking if host==us: 15==13 &&  [192.168.222.201] == [192.168.1.129] 
Jul  4 14:04:41 openser-pri openser[26013]: grep_sock_info - checking if port 5060 matches port 5060 
Jul  4 14:04:41 openser-pri openser[26013]: grep_sock_info - checking if host==us: 15==13 &&  [192.168.222.201] == [192.168.1.129] 
Jul  4 14:04:41 openser-pri openser[26013]: grep_sock_info - checking if port 5060 matches port 5060 
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG:check_self: host != me 
Jul  4 14:04:41 openser-pri openser[26013]: grep_sock_info - checking if host==us: 13==13 &&  [192.168.1.129] == [192.168.1.129] 
Jul  4 14:04:41 openser-pri openser[26013]: grep_sock_info - checking if port 5060 matches port 5060 
Jul  4 14:04:41 openser-pri openser[26013]: after_loose: Topmost route URI: 'sip:192.168.1.129;lr=on;ftag=339ca97a42' is me 
Jul  4 14:04:41 openser-pri openser[26013]: parse_headers: flags=200 
Jul  4 14:04:41 openser-pri openser[26013]: get_hdr_field: cseq <CSeq>: <28916> <ACK> 
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG: get_hdr_body : content_length=160 
Jul  4 14:04:41 openser-pri openser[26013]: found end of header 
Jul  4 14:04:41 openser-pri openser[26013]: find_next_route: No next Route HF found 
Jul  4 14:04:41 openser-pri openser[26013]: after_loose: No next URI found 
Jul  4 14:04:41 openser-pri openser[26013]: DBG:rr:run_rr_callbacks: callback id 0 entered with <lr=on;ftag=339ca97a42> 
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG:dialog:dlg_onroute: Route param 'did' not found 
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG: t_newtran:  T on entrance=0xffffffff 
Jul  4 14:04:41 openser-pri openser[26013]: parse_headers: flags=ffffffffffffffff 
Jul  4 14:04:41 openser-pri openser[26013]: parse_headers: flags=78 
Jul  4 14:04:41 openser-pri openser[26013]: t_lookup_request: start searching: hash=20284, isACK=1 
Jul  4 14:04:41 openser-pri openser[26013]: parse_headers: flags=38 
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG:tm:REF_UNSAFE: after is 2 
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG: t_lookup_request: e2e proxy ACK found 
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG:tm:t_newtran: building branch for end2end ACK 
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG:tm:t_relay: forwarding ACK 
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG: mk_proxy: doing DNS lookup... 
Jul  4 14:04:41 openser-pri openser[26013]: check_via_address(192.168.100.125, 192.168.100.125, 0) 
Jul  4 14:04:41 openser-pri openser[26013]: DBG:check_against_rule_list: using list dns  
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG:forward_request: sending: ACK sip:0615196262@192.168.222.201:5060 SIP/2.0^M Record-Route: <sip:192.168.1.129;lr=on;ftag=339ca97a42>^M Via: SIP/2.0/UDP 192.168.1.129;branch=z9hG4bKc3f4.5a795ab6.2^M Via: SIP/2.0/UDP 192.168.100.125:5060;branch=z9hG4bKc359e02551e314103^M Proxy-Authorization: Digest username="104",realm="barik.com",nonce="468b8df802b2bf130419f00dc437f4309dec9632",uri="sip:0615196262@192.168.222.201:5060",response="c007a5d327f679fe3ef1e6364ed7ab8e"^M Max-Forwards: 69^M From: Arturo <sip:104@barik.com>;tag=339ca97a42^M To: 0615196262 <sip:0615196262@barik.com>;tag=D2C738-17AF^M Call-ID: 7e873a6807f32663^M CSeq: 28916 ACK^M User-Agent: Aastra 57i/2.1.0.2141^M Content-Type: application/sdp^M Content-Length: 160^M ^M v=0^M o=MxSIP 0 22558 IN IP4 192.168.100.125^M s=SIP Call^M c=IN IP4 192.168.100.125^M t=0 0^M m=audio 3000 RTP/AVP 0^M a=rtpmap:0 PCMU/8000^M a=ptime:20^M a=sendrecv^M . 
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG:forward_request: orig. len=786, new_len=855, proto=1 
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG:tm:UNREF_UNSAFE: after is 1 
Jul  4 14:04:41 openser-pri openser[26013]: DEBUG:destroy_avp_list: destroying list (nil) 
Jul  4 14:04:41 openser-pri openser[26013]: receive_msg: cleaning up 
Jul  4 14:04:41 openser-pri openser[26026]: ERROR: receive_fd: EOF on 12 
Jul  4 14:04:41 openser-pri openser[26026]: DBG: handle_ser_child: dead child 6, pid 26016 (shutting down?) 
Jul  4 14:04:41 openser-pri openser[26026]: DBG: io_watch_del (0x812d720, 12, -1, 0x0) fd_no=23 called 
Jul  4 14:04:41 openser-pri openser[26010]: child process 26016 exited by a signal 11 
Jul  4 14:04:41 openser-pri openser[26010]: core was generated 
Jul  4 14:04:41 openser-pri openser[26010]: INFO: terminating due to SIGCHLD 
Jul  4 14:04:41 openser-pri openser[26026]: INFO: signal 15 received 
Jul  4 14:04:41 openser-pri openser[26025]: INFO: signal 15 received 
Jul  4 14:04:41 openser-pri openser[26026]: Memory status (pkg): 
Jul  4 14:04:41 openser-pri openser[26025]: Memory status (pkg): 
Jul  4 14:04:41 openser-pri openser[26026]: fm_status (0x816e3e0): 
Jul  4 14:04:41 openser-pri openser[26029]: INFO: signal 15 received 
Jul  4 14:04:41 openser-pri openser[26025]: fm_status (0x816e3e0): 
Jul  4 14:04:41 openser-pri openser[26026]:  heap size= 1048576 
Jul  4 14:04:41 openser-pri openser[26022]: INFO: signal 15 received 
Jul  4 14:04:41 openser-pri openser[26025]:  heap size= 1048576 
Jul  4 14:04:41 openser-pri openser[26026]:  used= 202600, used+overhead=234200, free=814376 
Jul  4 14:04:41 openser-pri openser[26023]: INFO: signal 15 received 
Jul  4 14:04:41 openser-pri openser[26018]: INFO: signal 15 received 
Jul  4 14:04:41 openser-pri openser[26017]: INFO: signal 15 received 
Jul  4 14:04:41 openser-pri openser[26022]: Memory status (pkg): 
Jul  4 14:04:41 openser-pri openser[26020]: INFO: signal 15 received 
Jul  4 14:04:41 openser-pri openser[26015]: INFO: signal 15 received 
Jul  4 14:04:41 openser-pri openser[26019]: INFO: signal 15 received 
Jul  4 14:04:41 openser-pri openser[26025]:  used= 211336, used+overhead=243096, free=805480 
Jul  4 14:04:41 openser-pri openser[26014]: INFO: signal 15 received 
Jul  4 14:04:41 openser-pri openser[26013]: INFO: signal 15 received 
Jul  4 14:04:41 openser-pri openser[26026]:  max used (+overhead)= 234200 
Jul  4 14:04:41 openser-pri openser[26012]: INFO: signal 15 received 
Jul  4 14:04:41 openser-pri openser[26011]: INFO: signal 15 received 
Jul  4 14:04:41 openser-pri openser[26023]: Memory status (pkg): 
Jul  4 14:04:41 openser-pri openser[26028]: INFO: signal 15 received 
Jul  4 14:04:41 openser-pri openser[26018]: Memory status (pkg): 
Jul  4 14:04:41 openser-pri openser[26017]: Memory status (pkg): 
Jul  4 14:04:41 openser-pri openser[26022]: fm_status (0x816e3e0): 
Jul  4 14:04:41 openser-pri openser[26020]: Memory status (pkg): 
Jul  4 14:04:41 openser-pri openser[26015]: Memory status (pkg): 
Jul  4 14:04:41 openser-pri openser[26019]: Memory status (pkg): 
Jul  4 14:04:41 openser-pri openser[26025]:  max used (+overhead)= 243096 
Jul  4 14:04:41 openser-pri openser[26014]: Memory status (pkg): 
Jul  4 14:04:41 openser-pri openser[26013]: Memory status (pkg): 
Jul  4 14:04:41 openser-pri openser[26026]: dumping free list: 
Jul  4 14:04:41 openser-pri openser[26012]: Memory status (pkg): 
Jul  4 14:04:41 openser-pri openser[26011]: Memory status (pkg): 
Jul  4 14:04:41 openser-pri openser[26023]: fm_status (0x816e3e0): 
Jul  4 14:04:41 openser-pri openser[26028]: Memory status (pkg): 
Jul  4 14:04:41 openser-pri openser[26018]: fm_status (0x816e3e0): 
Jul  4 14:04:41 openser-pri openser[26017]: fm_status (0x816e3e0): 
Jul  4 14:04:41 openser-pri openser[26022]:  heap size= 1048576 
Jul  4 14:04:41 openser-pri openser[26020]: fm_status (0x816e3e0): 
Jul  4 14:04:41 openser-pri openser[26015]: fm_status (0x816e3e0): 
Jul  4 14:04:41 openser-pri openser[26019]: fm_status (0x816e3e0): 
Jul  4 14:04:41 openser-pri openser[26025]: dumping free list: 
Jul  4 14:04:41 openser-pri openser[26014]: fm_status (0x816e3e0): 
Jul  4 14:04:41 openser-pri openser[26013]: fm_status (0x816e3e0): 
Jul  4 14:04:41 openser-pri openser[26026]: hash =  13 fragments no.:     1, unused:     0 ^I^I bucket size:       104 -       104 (first       104) 
Jul  4 14:04:41 openser-pri openser[26012]: fm_status (0x816e3e0): 
Jul  4 14:04:41 openser-pri openser[26011]: fm_status (0x816e3e0): 
Jul  4 14:04:41 openser-pri openser[26023]:  heap size= 1048576 
Jul  4 14:04:41 openser-pri openser[26024]: INFO: signal 15 received 
Jul  4 14:04:41 openser-pri openser[26018]:  heap size= 1048576 
Jul  4 14:04:41 openser-pri openser[26017]:  heap size= 1048576 
Jul  4 14:04:41 openser-pri openser[26022]:  used= 211336, used+overhead=243096, free=805480 
Jul  4 14:04:41 openser-pri openser[26020]:  heap size= 1048576 
Jul  4 14:04:41 openser-pri openser[26015]:  heap size= 1048576 
Jul  4 14:04:41 openser-pri openser[26019]:  heap size= 1048576 
Jul  4 14:04:41 openser-pri openser[26025]: hash = 2054 fragments no.:     1, unused:     0 ^I^I bucket size:    524288 -   1048576 (first    805624) 
Jul  4 14:04:41 openser-pri openser[26014]:  heap size= 1048576 
Jul  4 14:04:41 openser-pri openser[26013]:  heap size= 1048576 
Jul  4 14:04:41 openser-pri openser[26026]: hash =  17 fragments no.:     1, unused:     0 ^I^I bucket size:       136 -       136 (first       136) 
Jul  4 14:04:41 openser-pri openser[26012]:  heap size= 1048576 
Jul  4 14:04:41 openser-pri openser[26011]:  heap size= 1048576 
Jul  4 14:04:41 openser-pri openser[26023]:  used= 211336, used+overhead=243096, free=805480 
Jul  4 14:04:41 openser-pri openser[26029]: Memory status (pkg): 
Jul  4 14:04:41 openser-pri openser[26021]: INFO: signal 15 received 
Jul  4 14:04:41 openser-pri openser[26028]: fm_status (0x816e3e0): 
Jul  4 14:04:41 openser-pri openser[26024]: Memory status (pkg): 
Jul  4 14:04:41 openser-pri openser[26018]:  used= 160840, used+overhead=192504, free=856072 
Jul  4 14:04:41 openser-pri openser[26017]:  used= 161320, used+overhead=193576, free=855000 
Jul  4 14:04:41 openser-pri openser[26022]:  max used (+overhead)= 243096 
Jul  4 14:04:41 openser-pri openser[26020]:  used= 211336, used+overhead=243096, free=805480 
Jul  4 14:04:41 openser-pri openser[26015]:  used= 161408, used+overhead=193680, free=854896 
Jul  4 14:04:41 openser-pri openser[26019]:  used= 211336, used+overhead=243096, free=805480 
Jul  4 14:04:41 openser-pri openser[26025]: TOTAL:      1 free fragments = 805624 free bytes 
Jul  4 14:04:41 openser-pri openser[26014]:  used= 161320, used+overhead=193600, free=854976 
Jul  4 14:04:41 openser-pri openser[26013]:  used= 161392, used+overhead=193656, free=854920 
Jul  4 14:04:41 openser-pri openser[26026]: hash = 2054 fragments no.:     1, unused:     0 ^I^I bucket size:    524288 -   1048576 (first    814280) 
Jul  4 14:04:41 openser-pri openser[26012]:  used= 161408, used+overhead=193680, free=854896 
Jul  4 14:04:41 openser-pri openser[26011]:  used= 161456, used+overhead=193704, free=854872 
Jul  4 14:04:41 openser-pri openser[26023]:  max used (+overhead)= 243096 
Jul  4 14:04:41 openser-pri openser[26029]: fm_status (0x816e3e0): 
Jul  4 14:04:41 openser-pri openser[26021]: Memory status (pkg): 
Jul  4 14:04:41 openser-pri openser[26028]:  heap size= 1048576 
Jul  4 14:04:41 openser-pri openser[26024]: fm_status (0x816e3e0): 
Jul  4 14:04:41 openser-pri openser[26018]:  max used (+overhead)= 192728 
Jul  4 14:04:41 openser-pri openser[26017]:  max used (+overhead)= 197040 
Jul  4 14:04:41 openser-pri openser[26022]: dumping free list: 
Jul  4 14:04:41 openser-pri openser[26020]:  max used (+overhead)= 243096 
Jul  4 14:04:41 openser-pri openser[26015]:  max used (+overhead)= 197424 
Jul  4 14:04:41 openser-pri openser[26019]:  max used (+overhead)= 243096 
Jul  4 14:04:41 openser-pri openser[26025]: ----------------------------- 
Jul  4 14:04:41 openser-pri openser[26014]:  max used (+overhead)= 198856 
Jul  4 14:04:41 openser-pri openser[26013]:  max used (+overhead)= 198856 
Jul  4 14:04:41 openser-pri openser[26026]: TOTAL:      3 free fragments = 814520 free bytes 
Jul  4 14:04:41 openser-pri openser[26012]:  max used (+overhead)= 198776 
Jul  4 14:04:41 openser-pri openser[26011]:  max used (+overhead)= 198232 
Jul  4 14:04:41 openser-pri openser[26023]: dumping free list: 
Jul  4 14:04:41 openser-pri openser[26023]: hash = 2054 fragments no.:     1, unused:     0 ^I^I bucket size:    524288 -   1048576 (first    805624) 
Jul  4 14:04:41 openser-pri openser[26021]: fm_status (0x816e3e0): 
Jul  4 14:04:41 openser-pri openser[26028]:  used= 173480, used+overhead=205992, free=842584 
Jul  4 14:04:41 openser-pri openser[26024]:  heap size= 1048576 
Jul  4 14:04:41 openser-pri openser[26018]: dumping free list: 
Jul  4 14:04:41 openser-pri openser[26017]: dumping free list: 
Jul  4 14:04:41 openser-pri openser[26022]: hash = 2054 fragments no.:     1, unused:     0 ^I^I bucket size:    524288 -   1048576 (first    805624) 
Jul  4 14:04:41 openser-pri openser[26020]: dumping free list: 
Jul  4 14:04:41 openser-pri openser[26015]: dumping free list: 
Jul  4 14:04:41 openser-pri openser[26019]: dumping free list: 
Jul  4 14:04:41 openser-pri openser[26014]: dumping free list: 
Jul  4 14:04:41 openser-pri openser[26013]: dumping free list: 
Jul  4 14:04:41 openser-pri openser[26026]: ----------------------------- 
Jul  4 14:04:41 openser-pri openser[26012]: dumping free list: 
Jul  4 14:04:41 openser-pri openser[26011]: dumping free list: 
Jul  4 14:04:41 openser-pri openser[26029]:  heap size= 1048576 
Jul  4 14:04:41 openser-pri openser[26023]: TOTAL:      1 free fragments = 805624 free bytes 
Jul  4 14:04:41 openser-pri openser[26021]:  heap size= 1048576 
Jul  4 14:04:41 openser-pri openser[26028]:  max used (+overhead)= 207104 
Jul  4 14:04:41 openser-pri openser[26024]:  used= 211336, used+overhead=243096, free=805480 
Jul  4 14:04:41 openser-pri openser[26018]: hash =   3 fragments no.:     2, unused:     0 ^I^I bucket size:        24 -        24 (first        24) 
Jul  4 14:04:41 openser-pri openser[26017]: hash =   1 fragments no.:     4, unused:     0 ^I^I bucket size:         8 -         8 (first         8) 
Jul  4 14:04:41 openser-pri openser[26022]: TOTAL:      1 free fragments = 805624 free bytes 
Jul  4 14:04:41 openser-pri openser[26020]: hash = 2054 fragments no.:     1, unused:     0 ^I^I bucket size:    524288 -   1048576 (first    805624) 
Jul  4 14:04:41 openser-pri openser[26015]: hash =   1 fragments no.:     7, unused:     0 ^I^I bucket size:         8 -         8 (first         8) 
Jul  4 14:04:41 openser-pri openser[26019]: hash = 2054 fragments no.:     1, unused:     0 ^I^I bucket size:    524288 -   1048576 (first    805624) 
Jul  4 14:04:41 openser-pri openser[26014]: hash =   1 fragments no.:     5, unused:     0 ^I^I bucket size:         8 -         8 (first         8) 
Jul  4 14:04:41 openser-pri openser[26013]: hash =   1 fragments no.:     5, unused:     0 ^I^I bucket size:         8 -         8 (first         8) 
Jul  4 14:04:41 openser-pri openser[26012]: hash =   1 fragments no.:     5, unused:     0 ^I^I bucket size:         8 -         8 (first         8) 
Jul  4 14:04:41 openser-pri openser[26011]: hash =   1 fragments no.:     4, unused:     0 ^I^I bucket size:         8 -         8 (first         8) 
Jul  4 14:04:41 openser-pri openser[26029]:  used= 170192, used+overhead=202296, free=846280 
Jul  4 14:04:41 openser-pri openser[26023]: ----------------------------- 
Jul  4 14:04:41 openser-pri openser[26021]:  used= 211336, used+overhead=243096, free=805480 
Jul  4 14:04:41 openser-pri openser[26028]: dumping free list: 
Jul  4 14:04:41 openser-pri openser[26024]:  max used (+overhead)= 243096 
Jul  4 14:04:41 openser-pri openser[26018]: hash =   5 fragments no.:     1, unused:     0 ^I^I bucket size:        40 -        40 (first        40) 
Jul  4 14:04:41 openser-pri openser[26017]: hash =   2 fragments no.:     2, unused:     0 ^I^I bucket size:        16 -        16 (first        16) 
Jul  4 14:04:41 openser-pri openser[26022]: ----------------------------- 
Jul  4 14:04:41 openser-pri openser[26015]: hash =   2 fragments no.:     1, unused:     0 ^I^I bucket size:        16 -        16 (first        16) 
Jul  4 14:04:41 openser-pri openser[26015]: hash =   3 fragments no.:     7, unused:     0 ^I^I bucket size:        24 -        24 (first        24) 
Jul  4 14:04:41 openser-pri openser[26014]: hash =   2 fragments no.:     3, unused:     0 ^I^I bucket size:        16 -        16 (first        16) 
Jul  4 14:04:41 openser-pri openser[26014]: hash =   3 fragments no.:     7, unused:     0 ^I^I bucket size:        24 -        24 (first        24) 
Jul  4 14:04:41 openser-pri openser[26013]: hash =   2 fragments no.:     3, unused:     0 ^I^I bucket size:        16 -        16 (first        16) 
Jul  4 14:04:41 openser-pri openser[26012]: hash =   2 fragments no.:     3, unused:     0 ^I^I bucket size:        16 -        16 (first        16) 
Jul  4 14:04:41 openser-pri openser[26011]: hash =   2 fragments no.:     4, unused:     0 ^I^I bucket size:        16 -        16 (first        16) 
Jul  4 14:04:41 openser-pri openser[26029]:  max used (+overhead)= 202296 
Jul  4 14:04:41 openser-pri openser[26021]:  max used (+overhead)= 243096 
Jul  4 14:04:41 openser-pri openser[26028]: hash =   1 fragments no.:     1, unused:     0 ^I^I bucket size:         8 -         8 (first         8) 
Jul  4 14:04:41 openser-pri openser[26018]: hash =  17 fragments no.:     1, unused:     0 ^I^I bucket size:       136 -       136 (first       136) 
Jul  4 14:04:41 openser-pri openser[26018]: hash = 2054 fragments no.:     1, unused:     0 ^I^I bucket size:    524288 -   1048576 (first    855992) 
Jul  4 14:04:41 openser-pri openser[26017]: hash =   3 fragments no.:     7, unused:     0 ^I^I bucket size:        24 -        24 (first        24) 
Jul  4 14:04:41 openser-pri openser[26015]: hash =   4 fragments no.:    24, unused:     0 ^I^I bucket size:        32 -        32 (first        32) 
Jul  4 14:04:41 openser-pri openser[26014]: hash =   4 fragments no.:    26, unused:     0 ^I^I bucket size:        32 -        32 (first        32) 
Jul  4 14:04:41 openser-pri openser[26013]: hash =   3 fragments no.:     7, unused:     0 ^I^I bucket size:        24 -        24 (first        24) 
Jul  4 14:04:41 openser-pri openser[26012]: hash =   3 fragments no.:     7, unused:     0 ^I^I bucket size:        24 -        24 (first        24) 
Jul  4 14:04:41 openser-pri openser[26011]: hash =   3 fragments no.:     5, unused:     0 ^I^I bucket size:        24 -        24 (first        24) 
Jul  4 14:04:41 openser-pri openser[26029]: dumping free list: 
Jul  4 14:04:41 openser-pri openser[26021]: dumping free list: 
Jul  4 14:04:41 openser-pri openser[26028]: hash =   2 fragments no.:     1, unused:     0 ^I^I bucket size:        16 -        16 (first        16) 
Jul  4 14:04:41 openser-pri openser[26018]: TOTAL:      5 free fragments = 856216 free bytes 
Jul  4 14:04:41 openser-pri openser[26017]: hash =   4 fragments no.:    26, unused:     0 ^I^I bucket size:        32 -        32 (first        32) 
Jul  4 14:04:41 openser-pri openser[26015]: hash =   5 fragments no.:    14, unused:     0 ^I^I bucket size:        40 -        40 (first        40) 
Jul  4 14:04:41 openser-pri openser[26014]: hash =   5 fragments no.:    14, unused:     0 ^I^I bucket size:        40 -        40 (first        40) 
Jul  4 14:04:41 openser-pri openser[26020]: TOTAL:      1 free fragments = 805624 free bytes 
Jul  4 14:04:41 openser-pri openser[26019]: TOTAL:      1 free fragments = 805624 free bytes 
Jul  4 14:04:41 openser-pri openser[26013]: hash =   4 fragments no.:    24, unused:     0 ^I^I bucket size:        32 -        32 (first        32) 
Jul  4 14:04:41 openser-pri openser[26012]: hash =   4 fragments no.:    24, unused:     0 ^I^I bucket size:        32 -        32 (first        32) 
Jul  4 14:04:41 openser-pri openser[26024]: dumping free list: 
Jul  4 14:04:41 openser-pri openser[26011]: hash =   4 fragments no.:    13, unused:     0 ^I^I bucket size:        32 -        32 (first        32) 
Jul  4 14:04:41 openser-pri openser[26029]: hash =  18 fragments no.:     1, unused:     0 ^I^I bucket size:       144 -       144 (first       144) 
Jul  4 14:04:41 openser-pri openser[26021]: hash = 2054 fragments no.:     1, unused:     0 ^I^I bucket size:    524288 -   1048576 (first    805624) 
Jul  4 14:04:41 openser-pri openser[26028]: hash =   3 fragments no.:     1, unused:     0 ^I^I bucket size:        24 -        24 (first        24) 
Jul  4 14:04:41 openser-pri openser[26018]: ----------------------------- 
Jul  4 14:04:41 openser-pri openser[26020]: ----------------------------- 
Jul  4 14:04:41 openser-pri openser[26019]: ----------------------------- 
Jul  4 14:04:41 openser-pri openser[26015]: hash =   6 fragments no.:     1, unused:     0 ^I^I bucket size:        48 -        48 (first        48) 
Jul  4 14:04:41 openser-pri openser[26015]: hash =   7 fragments no.:     1, unused:     0 ^I^I bucket size:        56 -        56 (first        56) 
Jul  4 14:04:41 openser-pri openser[26017]: hash =   5 fragments no.:    12, unused:     0 ^I^I bucket size:        40 -        40 (first        40) 
Jul  4 14:04:41 openser-pri openser[26015]: hash =   9 fragments no.:     1, unused:     0 ^I^I bucket size:        72 -        72 (first        72) 
Jul  4 14:04:41 openser-pri openser[26015]: hash =  15 fragments no.:     1, unused:     0 ^I^I bucket size:       120 -       120 (first       120) 
Jul  4 14:04:41 openser-pri openser[26015]: hash =  27 fragments no.:     2, unused:     0 ^I^I bucket size:       216 -       216 (first       216) 
Jul  4 14:04:41 openser-pri openser[26017]: hash =   6 fragments no.:     1, unused:     0 ^I^I bucket size:        48 -        48 (first        48) 
Jul  4 14:04:41 openser-pri openser[26015]: hash =  37 fragments no.:     1, unused:     0 ^I^I bucket size:       296 -       296 (first       296) 
Jul  4 14:04:41 openser-pri openser[26017]: hash =   9 fragments no.:     2, unused:     0 ^I^I bucket size:        72 -        72 (first        72) 
Jul  4 14:04:41 openser-pri openser[26015]: hash =  46 fragments no.:     1, unused:     0 ^I^I bucket size:       368 -       368 (first       368) 
Jul  4 14:04:41 openser-pri openser[26017]: hash =  14 fragments no.:     2, unused:     0 ^I^I bucket size:       112 -       112 (first       112) 
Jul  4 14:04:41 openser-pri openser[26017]: hash =  15 fragments no.:     1, unused:     0 ^I^I bucket size:       120 -       120 (first       120) 
Jul  4 14:04:41 openser-pri openser[26013]: hash =   5 fragments no.:    12, unused:     0 ^I^I bucket size:        40 -        40 (first        40) 
Jul  4 14:04:41 openser-pri openser[26011]: hash =   5 fragments no.:    18, unused:     0 ^I^I bucket size:        40 -        40 (first        40) 
Jul  4 14:04:41 openser-pri openser[26017]: hash =  16 fragments no.:     1, unused:     0 ^I^I bucket size:       128 -       128 (first       128) 
Jul  4 14:04:41 openser-pri openser[26014]: hash =   6 fragments no.:     2, unused:     0 ^I^I bucket size:        48 -        48 (first        48) 
Jul  4 14:04:41 openser-pri openser[26012]: hash =   5 fragments no.:    11, unused:     0 ^I^I bucket size:        40 -        40 (first        40) 
Jul  4 14:04:41 openser-pri openser[26029]: hash = 2054 fragments no.:     1, unused:     0 ^I^I bucket size:    524288 -   1048576 (first    846280) 
Jul  4 14:04:41 openser-pri openser[26028]: hash =   4 fragments no.:     9, unused:     0 ^I^I bucket size:        32 -        32 (first        32) 
Jul  4 14:04:41 openser-pri openser[26013]: hash =   6 fragments no.:     2, unused:     0 ^I^I bucket size:        48 -        48 (first        48) 
Jul  4 14:04:41 openser-pri openser[26011]: hash =   6 fragments no.:     7, unused:     0 ^I^I bucket size:        48 -        48 (first        48) 
Jul  4 14:04:41 openser-pri openser[26017]: hash =  27 fragments no.:     1, unused:     0 ^I^I bucket size:       216 -       216 (first       216) 
Jul  4 14:04:41 openser-pri openser[26014]: hash =   9 fragments no.:     2, unused:     0 ^I^I bucket size:        72 -        72 (first        72) 
Jul  4 14:04:41 openser-pri openser[26012]: hash =   6 fragments no.:     2, unused:     0 ^I^I bucket size:        48 -        48 (first        48) 
Jul  4 14:04:41 openser-pri openser[26024]: hash = 2054 fragments no.:     1, unused:     0 ^I^I bucket size:    524288 -   1048576 (first    805624) 
Jul  4 14:04:41 openser-pri openser[26029]: TOTAL:      2 free fragments = 846424 free bytes 
Jul  4 14:04:41 openser-pri openser[26028]: hash =   5 fragments no.:    20, unused:     0 ^I^I bucket size:        40 -        40 (first        40) 
Jul  4 14:04:41 openser-pri openser[26013]: hash =   9 fragments no.:     1, unused:     0 ^I^I bucket size:        72 -        72 (first        72) 
Jul  4 14:04:41 openser-pri openser[26011]: hash =   7 fragments no.:     2, unused:     0 ^I^I bucket size:        56 -        56 (first        56) 
Jul  4 14:04:41 openser-pri openser[26017]: hash =  34 fragments no.:     1, unused:     0 ^I^I bucket size:       272 -       272 (first       272) 
Jul  4 14:04:41 openser-pri openser[26021]: TOTAL:      1 free fragments = 805624 free bytes 
Jul  4 14:04:41 openser-pri openser[26014]: hash =  15 fragments no.:     1, unused:     0 ^I^I bucket size:       120 -       120 (first       120) 
Jul  4 14:04:41 openser-pri openser[26012]: hash =   9 fragments no.:     2, unused:     0 ^I^I bucket size:        72 -        72 (first        72) 
Jul  4 14:04:41 openser-pri openser[26024]: TOTAL:      1 free fragments = 805624 free bytes 
Jul  4 14:04:41 openser-pri openser[26029]: ----------------------------- 
Jul  4 14:04:41 openser-pri openser[26011]: hash =  14 fragments no.:     1, unused:     0 ^I^I bucket size:       112 -       112 (first       112) 
Jul  4 14:04:41 openser-pri openser[26011]: hash =  16 fragments no.:     1, unused:     0 ^I^I bucket size:       128 -       128 (first       128) 
Jul  4 14:04:41 openser-pri openser[26011]: hash =  19 fragments no.:     1, unused:     0 ^I^I bucket size:       152 -       152 (first       152) 
Jul  4 14:04:41 openser-pri openser[26017]: hash =  39 fragments no.:     1, unused:     0 ^I^I bucket size:       312 -       312 (first       312) 
Jul  4 14:04:41 openser-pri openser[26021]: ----------------------------- 
Jul  4 14:04:41 openser-pri openser[26014]: hash =  27 fragments no.:     2, unused:     0 ^I^I bucket size:       216 -       216 (first       216) 
Jul  4 14:04:41 openser-pri openser[26012]: hash =  15 fragments no.:     1, unused:     0 ^I^I bucket size:       120 -       120 (first       120) 
Jul  4 14:04:41 openser-pri openser[26024]: ----------------------------- 
Jul  4 14:04:41 openser-pri openser[26011]: hash =  30 fragments no.:     1, unused:     0 ^I^I bucket size:       240 -       240 (first       240) 
Jul  4 14:04:41 openser-pri openser[26017]: hash =  58 fragments no.:     1, unused:     0 ^I^I bucket size:       464 -       464 (first       464) 
Jul  4 14:04:41 openser-pri openser[26014]: hash =  43 fragments no.:     1, unused:     0 ^I^I bucket size:       344 -       344 (first       344) 
Jul  4 14:04:41 openser-pri openser[26012]: hash =  17 fragments no.:     1, unused:     0 ^I^I bucket size:       136 -       136 (first       136) 
Jul  4 14:04:41 openser-pri openser[26017]: hash = 100 fragments no.:     1, unused:     0 ^I^I bucket size:       800 -       800 (first       800) 
Jul  4 14:04:41 openser-pri openser[26013]: hash =  15 fragments no.:     1, unused:     0 ^I^I bucket size:       120 -       120 (first       120) 
Jul  4 14:04:41 openser-pri openser[26028]: hash =   6 fragments no.:     6, unused:     0 ^I^I bucket size:        48 -        48 (first        48) 
Jul  4 14:04:41 openser-pri openser[26015]: hash =  48 fragments no.:     1, unused:     0 ^I^I bucket size:       384 -       384 (first       384) 
Jul  4 14:04:41 openser-pri openser[26014]: hash = 100 fragments no.:     1, unused:     0 ^I^I bucket size:       800 -       800 (first       800) 
Jul  4 14:04:41 openser-pri openser[26012]: hash =  27 fragments no.:     2, unused:     0 ^I^I bucket size:       216 -       216 (first       216) 
Jul  4 14:04:41 openser-pri openser[26017]: hash = 2054 fragments no.:     1, unused:     0 ^I^I bucket size:    524288 -   1048576 (first    850872) 
Jul  4 14:04:41 openser-pri openser[26013]: hash =  26 fragments no.:     1, unused:     0 ^I^I bucket size:       208 -       208 (first       208) 
Jul  4 14:04:41 openser-pri openser[26028]: hash =   7 fragments no.:     2, unused:     0 ^I^I bucket size:        56 -        56 (first        56) 
Jul  4 14:04:41 openser-pri openser[26015]: hash =  70 fragments no.:     1, unused:     0 ^I^I bucket size:       560 -       560 (first       560) 
Jul  4 14:04:41 openser-pri openser[26014]: hash = 128 fragments no.:     1, unused:     0 ^I^I bucket size:      1024 -      1024 (first      1024) 
Jul  4 14:04:41 openser-pri openser[26012]: hash =  35 fragments no.:     1, unused:     0 ^I^I bucket size:       280 -       280 (first       280) 
Jul  4 14:04:41 openser-pri openser[26017]: TOTAL:     64 free fragments = 855144 free bytes 
Jul  4 14:04:41 openser-pri openser[26013]: hash =  27 fragments no.:     2, unused:     0 ^I^I bucket size:       216 -       216 (first       216) 
Jul  4 14:04:41 openser-pri openser[26028]: hash =   8 fragments no.:     4, unused:     0 ^I^I bucket size:        64 -        64 (first        64) 
Jul  4 14:04:41 openser-pri openser[26015]: hash = 100 fragments no.:     1, unused:     0 ^I^I bucket size:       800 -       800 (first       800) 
Jul  4 14:04:41 openser-pri openser[26014]: hash = 163 fragments no.:     1, unused:     0 ^I^I bucket size:      1304 -      1304 (first      1304) 
Jul  4 14:04:41 openser-pri openser[26012]: hash =  48 fragments no.:     1, unused:     0 ^I^I bucket size:       384 -       384 (first       384) 
Jul  4 14:04:41 openser-pri openser[26017]: ----------------------------- 
Jul  4 14:04:41 openser-pri openser[26014]: hash = 2054 fragments no.:     1, unused:     0 ^I^I bucket size:    524288 -   1048576 (first    849208) 
Jul  4 14:04:41 openser-pri openser[26014]: TOTAL:     67 free fragments = 855120 free bytes 
Jul  4 14:04:41 openser-pri openser[26014]: ----------------------------- 
Jul  4 14:04:41 openser-pri openser[26013]: hash =  38 fragments no.:     1, unused:     0 ^I^I bucket size:       304 -       304 (first       304) 
Jul  4 14:04:41 openser-pri openser[26012]: hash =  79 fragments no.:     1, unused:     0 ^I^I bucket size:       632 -       632 (first       632) 
Jul  4 14:04:41 openser-pri openser[26013]: hash =  50 fragments no.:     1, unused:     0 ^I^I bucket size:       400 -       400 (first       400) 
Jul  4 14:04:41 openser-pri openser[26015]: hash = 2054 fragments no.:     1, unused:     0 ^I^I bucket size:    524288 -   1048576 (first    850336) 
Jul  4 14:04:41 openser-pri openser[26012]: hash = 100 fragments no.:     1, unused:     0 ^I^I bucket size:       800 -       800 (first       800) 
Jul  4 14:04:41 openser-pri openser[26013]: hash =  77 fragments no.:     1, unused:     0 ^I^I bucket size:       616 -       616 (first       616) 
Jul  4 14:04:41 openser-pri openser[26015]: TOTAL:     65 free fragments = 855040 free bytes 
Jul  4 14:04:41 openser-pri openser[26012]: hash = 143 fragments no.:     2, unused:     0 ^I^I bucket size:      1144 -      1144 (first      1144) 
Jul  4 14:04:41 openser-pri openser[26013]: hash = 100 fragments no.:     1, unused:     0 ^I^I bucket size:       800 -       800 (first       800) 
Jul  4 14:04:41 openser-pri openser[26015]: ----------------------------- 
Jul  4 14:04:41 openser-pri openser[26012]: hash = 2054 fragments no.:     1, unused:     0 ^I^I bucket size:    524288 -   1048576 (first    848264) 
Jul  4 14:04:41 openser-pri openser[26012]: TOTAL:     65 free fragments = 855040 free bytes 
Jul  4 14:04:41 openser-pri openser[26012]: ----------------------------- 
Jul  4 14:04:41 openser-pri openser[26028]: hash =  10 fragments no.:     3, unused:     0 ^I^I bucket size:        80 -        80 (first        80) 
Jul  4 14:04:41 openser-pri openser[26028]: hash =  11 fragments no.:     2, unused:     0 ^I^I bucket size:        88 -        88 (first        88) 
Jul  4 14:04:41 openser-pri openser[26028]: hash =  14 fragments no.:     1, unused:     0 ^I^I bucket size:       112 -       112 (first       112) 
Jul  4 14:04:41 openser-pri openser[26028]: hash =  23 fragments no.:     1, unused:     0 ^I^I bucket size:       184 -       184 (first       184) 
Jul  4 14:04:41 openser-pri openser[26028]: hash = 2054 fragments no.:     1, unused:     0 ^I^I bucket size:    524288 -   1048576 (first    840224) 
Jul  4 14:04:41 openser-pri openser[26028]: TOTAL:     52 free fragments = 842728 free bytes 
Jul  4 14:04:41 openser-pri openser[26028]: ----------------------------- 
Jul  4 14:04:41 openser-pri openser[26013]: hash = 163 fragments no.:     1, unused:     0 ^I^I bucket size:      1304 -      1304 (first      1304) 
Jul  4 14:04:41 openser-pri openser[26013]: hash = 2054 fragments no.:     1, unused:     0 ^I^I bucket size:    524288 -   1048576 (first    849208) 
Jul  4 14:04:41 openser-pri openser[26013]: TOTAL:     64 free fragments = 855064 free bytes 
Jul  4 14:04:41 openser-pri openser[26013]: -----------------------------