Re: Openser, Ekiga, Nathelper, Rtpproxy

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 




You are on the wrong list. This is a H.323 list. Try the openser list.

Simon

At 02:14 AM 19/04/2007, you wrote:
I'm trying to use openser, the default nathelper.cfg, and rtpproxy to connect two clients running ekiga. One is behind a NAT, the other isn't. They can both call each other, but it doesn't appear that the media connections are getting setup properly, as the call disconnects almost immediately. I've included the dumps from various applications, as I'm still very new to openser syntax and am not too sure what I need to fix in nathelper.cfg.

Openser dump:

 0(8358) loading module /usr/lib/openser/modules/sl.so
 0(8358) loading module /usr/lib/openser/modules/tm.so
 0(8358) loading module /usr/lib/openser/modules/rr.so
 0(8358) loading module /usr/lib/openser/modules/maxfwd.so
 0(8358) loading module /usr/lib/openser/modules/usrloc.so
 0(8358) loading module /usr/lib/openser/modules/registrar.so
 0(8358) loading module /usr/lib/openser/modules/textops.so
 0(8358) loading module /usr/lib/openser/modules/nathelper.so
 0(8358) set_mod_param_regex: usrloc matches module usrloc
 0(8358) set_mod_param_regex: found <db_mode> in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(8358) set_mod_param_regex: rr matches module rr
 0(8358) set_mod_param_regex: found <enable_full_lr> in module rr [/usr/lib/openser/modules/rr.so]
 0(8358) set_mod_param_regex: registrar matches module registrar
 0(8358) set_mod_param_regex: found <nat_flag> in module registrar [/usr/lib/openser/modules/registrar.so]
 0(8358) set_mod_param_regex: nathelper matches module nathelper
 0(8358) set_mod_param_regex: found <natping_interval> in module nathelper [/usr/lib/openser/modules/nathelper.so]
 0(8358) set_mod_param_regex: nathelper matches module nathelper
 0(8358) set_mod_param_regex: found <ping_nated_only> in module nathelper [/usr/lib/openser/modules/nathelper.so]
 0(8358) find_cmd_export_t: found <mf_process_maxfwd_header>(1) in module maxfwd [/usr/lib/openser/modules/maxfwd.so]
 0(8358) find_cmd_export_t: found <sl_send_reply>(2) in module sl [/usr/lib/openser/modules/sl.so]
 0(8358) find_cmd_export_t: found <sl_send_reply>(2) in module sl [/usr/lib/openser/modules/sl.so]
 0(8358) find_cmd_export_t: found <nat_uac_test>(1) in module nathelper [/usr/lib/openser/modules/nathelper.so]
 0(8358) find_cmd_export_t: found <search>(1) in module textops [/usr/lib/openser/modules/textops.so]
 0(8358) find_cmd_export_t: found <fix_nated_contact>(0) in module nathelper [/usr/lib/openser/modules/nathelper.so]
 0(8358) find_cmd_export_t: found <fix_nated_sdp>(1) in module nathelper [/usr/lib/openser/modules/nathelper.so]
 0(8358) find_cmd_export_t: found <record_route>(0) in module rr [/usr/lib/openser/modules/rr.so]
 0(8358) find_cmd_export_t: found <loose_route>(0) in module rr [/usr/lib/openser/modules/rr.so]
 0(8358) find_cmd_export_t: found <append_hf>(1) in module textops [/usr/lib/openser/modules/textops.so]
 0(8358) find_cmd_export_t: found <append_hf>(1) in module textops [/usr/lib/openser/modules/textops.so]
 0(8358) find_cmd_export_t: found <save>(1) in module registrar [/usr/lib/openser/modules/registrar.so]
 0(8358) find_cmd_export_t: found <lookup>(1) in module registrar [/usr/lib/openser/modules/registrar.so]
 0(8358) find_cmd_export_t: found <append_hf>(1) in module textops [/usr/lib/openser/modules/textops.so]
 0(8358) find_cmd_export_t: found <lookup>(1) in module registrar [/usr/lib/openser/modules/registrar.so]
 0(8358) find_cmd_export_t: found <sl_send_reply>(2) in module sl [/usr/lib/openser/modules/sl.so]
 0(8358) find_cmd_export_t: found <append_hf>(1) in module textops [/usr/lib/openser/modules/textops.so]
 0(8358) find_cmd_export_t: found <search>(1) in module textops [/usr/lib/openser/modules/textops.so]
 0(8358) find_cmd_export_t: found <sl_send_reply>(2) in module sl [/usr/lib/openser/modules/sl.so]
 0(8358) find_cmd_export_t: found <force_rtp_proxy>(0) in module nathelper [/usr/lib/openser/modules/nathelper.so]
 0(8358) find_cmd_export_t: found <t_on_reply>(1) in module tm [/usr/lib/openser/modules/tm.so]
 0(8358) find_cmd_export_t: found <t_relay>(0) in module tm [/usr/lib/openser/modules/tm.so]
 0(8358) find_cmd_export_t: found <sl_reply_error>(0) in module sl [/usr/lib/openser/modules/sl.so]
 0(8358) find_cmd_export_t: found <fix_nated_contact>(0) in module nathelper [/usr/lib/openser/modules/nathelper.so]
 0(8358) find_cmd_export_t: found <force_rtp_proxy>(0) in module nathelper [/usr/lib/openser/modules/nathelper.so]
 0(8358) find_cmd_export_t: found <nat_uac_test>(1) in module nathelper [/usr/lib/openser/modules/nathelper.so]
 0(8358) find_cmd_export_t: found <fix_nated_contact>(0) in module nathelper [/usr/lib/openser/modules/nathelper.so]
 0(8358) routing table 0:
 0(8358) if ( 0(8358) NOT(  0(8358)  external_module_call( 0(8358) f<mf_process_maxfwd_header> 0(8358) , "10" 0(8358) );  0(8358)  ) 0(8358) ) { 0(8358)  external_module_call( 0(8358) f<sl_send_reply> 0(8358) , "483" 0(8358) , "Too Many Hops" 0(8358) );  0(8358) return( 0(8358) 1 0(8358) );  0(8358) } else { 0(8358) };  0(8358) if ( 0(8358) UNKNOWN 0(8358) >= 0(8358) 65535 0(8358) ) { 0(8358)  external_module_call( 0(8358) f<sl_send_reply> 0(8358) , "513" 0(8358) , "Message too big" 0(8358) );  0(8358) return( 0(8358) 1 0(8358) );  0(8358) } else { 0(8358) };  0(8358) if ( 0(8358)  external_module_call( 0(8358) f<nat_uac_test> 0(8358) , "3" 0(8358) );  0(8358) ) { 0(8358) if ( 0(8358) OR(  0(8358) method 0(8358) == 0(8358) "REGISTER" 0(8358) ,  0(8358) NOT(  0(8358)  external_module_call( 0(8358) f<search> 0(8358) , "^Record-Route:" 0(8358) );  0(8358)  ) 0(8358)  ) 0(8358) ) { 0(8358) log( 0(8358) 4 0(8358) , "LOG: Someone trying to register from private IP, rewriting
" 0(8358) );  0(8358)  external_module_call( 0(8358) f<fix_nated_contact> 0(8358) );  0(8358) if ( 0(8358) method 0(8358) == 0(8358) "INVITE" 0(8358) ) { 0(8358)  external_module_call( 0(8358) f<fix_nated_sdp> 0(8358) , "1" 0(8358) );  0(8358) } else { 0(8358) };  0(8358) force_rport( 0(8358) type<0> 0(8358) );  0(8358) setflag( 0(8358) 6 0(8358) );  0(8358) } else { 0(8358) };  0(8358) } else { 0(8358) };  0(8358) if ( 0(8358) NOT(  0(8358) method 0(8358) == 0(8358) "REGISTER" 0(8358)  ) 0(8358) ) { 0(8358)  external_module_call( 0(8358) f<record_route> 0(8358) );  0(8358) } else { 0(8358) };  0(8358) if ( 0(8358)  external_module_call( 0(8358) f<loose_route> 0(8358) );  0(8358) ) { 0(8358)  external_module_call( 0(8358) f<append_hf> 0(8358) , "P-hint: rr-enforced
" 0(8358) );  0(8358) route( 0(8358) 1 0(8358) );  0(8358) return( 0(8358) 1 0(8358) );  0(8358) } else { 0(8358) };  0(8358) if ( 0(8358) NOT(  0(8358) uri 0(8358) == 0(8358) _myself_ 0(8358)  ) 0(8358) ) { 0(8358)  external_module_call( 0(8358) f<append_hf> 0(8358) , "P-hint: outbound
" 0(8358) );  0(8358) route( 0(8358) 1 0(8358) );  0(8358) return( 0(8358) 1 0(8358) );  0(8358) } else { 0(8358) };  0(8358) if ( 0(8358) uri 0(8358) == 0(8358) _myself_ 0(8358) ) { 0(8358) if ( 0(8358) method 0(8358) == 0(8358) "REGISTER" 0(8358) ) { 0(8358)  external_module_call( 0(8358) f<save> 0(8358) , "location" 0(8358) );  0(8358) return( 0(8358) 1 0(8358) );  0(8358) } else { 0(8358) };  0(8358)  external_module_call( 0(8358) f<lookup> 0(8358) , "aliases" 0(8358) );  0(8358) if ( 0(8358) NOT(  0(8358) uri 0(8358) == 0(8358) _myself_ 0(8358)  ) 0(8358) ) { 0(8358)  external_module_call( 0(8358) f<append_hf> 0(8358) , "P-hint: outbound alias
" 0(8358) );  0(8358) route( 0(8358) 1 0(8358) );  0(8358) return( 0(8358) 1 0(8358) );  0(8358) } else { 0(8358) };  0(8358) if ( 0(8358) NOT(  0(8358)  external_module_call( 0(8358) f<lookup> 0(8358) , "location" 0(8358) );  0(8358)  ) 0(8358) ) { 0(8358)  external_module_call( 0(8358) f<sl_send_reply> 0(8358) , "404" 0(8358) , "Not Found" 0(8358) );  0(8358) return( 0(8358) 1 0(8358) );  0(8358) } else { 0(8358) };  0(8358) } else { 0(8358) };  0(8358)  external_module_call( 0(8358) f<append_hf> 0(8358) , "P-hint: usrloc applied
" 0(8358) );  0(8358) route( 0(8358) 1 0(8358) );  0(8358)
 0(8358) routing table 1:
 0(8358) if ( 0(8358) AND(  0(8358) uri 0(8358) =~ 0(8358) "[@:](192\.168\.|10\.|172\.(1[6-9]|2[0-9]|3[0-1])\.)" 0(8358) ,  0(8358) NOT(  0(8358)  external_module_call( 0(8358) f<search> 0(8358) , "^Route:" 0(8358) );  0(8358)  ) 0(8358)  ) 0(8358) ) { 0(8358)  external_module_call( 0(8358) f<sl_send_reply> 0(8358) , "479" 0(8358) , "We don't forward to private IP addresses" 0(8358) );  0(8358) return( 0(8358) 1 0(8358) );  0(8358) } else { 0(8358) };  0(8358) if ( 0(8358) isflagset( 0(8358) 6 0(8358) );  0(8358) ) { 0(8358)  external_module_call( 0(8358) f<force_rtp_proxy> 0(8358) );  0(8358) } else { 0(8358) };  0(8358)  external_module_call( 0(8358) f<t_on_reply> 0(8358) , "1" 0(8358) );  0(8358) if ( 0(8358) NOT(  0(8358)  external_module_call( 0(8358) f<t_relay> 0(8358) );  0(8358)  ) 0(8358) ) { 0(8358)  external_module_call( 0(8358) f<sl_reply_error> 0(8358) );  0(8358) } else { 0(8358) };  0(8358)
 0(8358) onreply routing table 1:
 0(8358) if ( 0(8358) AND(  0(8358) isflagset( 0(8358) 6 0(8358) );  0(8358) ,  0(8358) uri 0(8358) =~ 0(8358) "(183)|2[0-9][0-9]" 0(8358)  ) 0(8358) ) { 0(8358)  external_module_call( 0(8358) f<fix_nated_contact> 0(8358) );  0(8358)  external_module_call( 0(8358) f<force_rtp_proxy> 0(8358) );  0(8358) } else { 0(8358) if ( 0(8358)  external_module_call( 0(8358) f<nat_uac_test> 0(8358) , "1" 0(8358) );  0(8358) ) { 0(8358)  external_module_call( 0(8358) f<fix_nated_contact> 0(8358) );  0(8358) } else { 0(8358) };  0(8358) };  0(8358)
 0(8358) DEBUG:socket2str: <udp:127.0.0.1:5060>
 0(8358) DEBUG:socket2str: <udp:169.198.11.95:5060>
 0(8358) DEBUG:socket2str: <udp: 169.198.11.110:5060>
 0(8358) DEBUG:socket2str: <tcp:127.0.0.1:5060>
 0(8358) DEBUG:socket2str: <tcp: 169.198.11.95:5060>
 0(8358) DEBUG:socket2str: <tcp:169.198.11.110:5060>
 0(8358) fm_malloc_init: F_OPTIMIZE=16384, /ROUNDTO=2048
 0(8358) fm_malloc_init: F_HASH_SIZE=2067, fm_block size=16560
 0(8358) fm_malloc_init(0xb5d3f000, 33554432), start=0xb5d3f000
 0(8358) shm_mem_init: success
 0(8358) init_tcp: using epoll_lt as the io watch method (auto detected)
 0(0) core dump limits set to 4294967295
 0(0) DEBUG:add_avp_galias: registering <serial_branch> for avp id <16725044>
 0(0) DEBUG: register_fifo_cmd: new command (get_statistics) registered
 0(0) DEBUG: register_fifo_cmd: new command (reset_statistics) registered
 0(0) INFO: statistics manager successfully initialized
 0(0) DEBUG: init_mod: sl
 0(0) StateLess module - initializing
 0(0) DEBUG: MD5 calculated: 329cfeaa6ded039da25ff8cbb8668bd2
 0(0) DEBUG: init_stats: sl
 0(0) DEBUG: init_mod: tm
 0(0) TM - initializing...
 0(0) Call-ID initialization: '67d5ffff'
 0(0) DEBUG: register_fifo_cmd: new command (t_uac_dlg) registered
 0(0) DEBUG: register_fifo_cmd: new command (t_uac_cancel) registered
 0(0) DEBUG: register_fifo_cmd: new command (t_hash) registered
 0(0) DEBUG: register_fifo_cmd: new command (t_reply) registered
 0(0) unixsock_register_cmd: New command (t_uac_dlg) registered
 0(0) unixsock_register_cmd: New command (t_uac_cancel) registered
 0(0) unixsock_register_cmd: New command (t_hash) registered
 0(0) unixsock_register_cmd: New command (t_reply) registered
 0(0) DEBUG: lock_initialize: lock initialization started
 0(0) DEBUG: MD5 calculated: 533cb9e91f4b999cf76861cbb9ed54ed
 0(0) DEBUG: MD5 calculated: fa997f81440371de71ab448ebdb9af56
 0(0) xl_add_extra_spec: extra items list is not initialized
 0(0) xl_add_extra_spec: inserting extra item [T_branch_idx] at [0]
 0(0) DEBUG: init_stats: tm
 0(0) DEBUG: init_mod: rr
 0(0) rr - initializing
 0(0) DEBUG: init_mod: maxfwd
 0(0) Maxfwd module- initializing
 0(0) DEBUG: init_mod: usrloc
 0(0) usrloc - initializing
 0(0) DEBUG: register_fifo_cmd: new command (ul_rm) registered
 0(0) DEBUG: register_fifo_cmd: new command (ul_rm_contact) registered
 0(0) DEBUG: register_fifo_cmd: new command (ul_dump) registered
 0(0) DEBUG: register_fifo_cmd: new command (ul_flush) registered
 0(0) DEBUG: register_fifo_cmd: new command (ul_add) registered
 0(0) DEBUG: register_fifo_cmd: new command (ul_show_contact) registered
 0(0) unixsock_register_cmd: New command (ul_rm) registered
 0(0) unixsock_register_cmd: New command (ul_rm_contact) registered
 0(0) unixsock_register_cmd: New command (ul_dump) registered
 0(0) unixsock_register_cmd: New command (ul_flush) registered
 0(0) unixsock_register_cmd: New command (ul_add) registered
 0(0) unixsock_register_cmd: New command (ul_show_contact) registered
 0(0) DEBUG: init_mod: registrar
 0(0) registrar - initializing
 0(0) find_cmd_export_t: found <sl_send_reply>(2) in module sl [/usr/lib/openser/modules/sl.so]
 0(0) find_cmd_export_t: found <ul_bind_usrloc>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_register_udomain>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_get_all_ucontacts>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_insert_urecord>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_delete_urecord>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_get_urecord>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_lock_udomain>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_unlock_udomain>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_release_urecord>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_insert_ucontact>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_delete_ucontact>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_get_ucontact>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_update_ucontact>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_register_watcher>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_unregister_watcher>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_register_ulcb>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) DEBUG: init_mod: textops
 0(0) TextOPS - initializing
 0(0) DEBUG: init_mod: nathelper
 0(0) find_cmd_export_t: found <ul_bind_usrloc>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_register_udomain>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_get_all_ucontacts>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_insert_urecord>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_delete_urecord>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_get_urecord>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_lock_udomain>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_unlock_udomain>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_release_urecord>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_insert_ucontact>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_delete_ucontact>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_get_ucontact>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_update_ucontact>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_register_watcher>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_unregister_watcher>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) find_cmd_export_t: found <ul_register_ulcb>(1) in module usrloc [/usr/lib/openser/modules/usrloc.so]
 0(0) fixing mf_process_maxfwd_header, line 96
 0(0) fixing sl_send_reply, line 97
 0(0) fixing sl_send_reply, line 101
 0(0) fixing nat_uac_test, line 111
 0(0) fixing search, line 116
 0(0) module - fixing ^Record-Route:
 0(0) fixing fix_nated_contact, line 125
 0(0) fixing fix_nated_sdp, line 127
 0(0) fixing record_route, line 138
 0(0) fixing loose_route, line 142
 0(0) fixing append_hf, line 144
 0(0) xl_parse_format: parsing [P-hint: rr-enforced
]
 0(0) xl_parse_format: format parsed OK: [1] items
 0(0) fixing append_hf, line 151
 0(0) xl_parse_format: parsing [P-hint: outbound
]
 0(0) xl_parse_format: format parsed OK: [1] items
 0(0) fixing save, line 169
 0(0) fixing lookup, line 173
 0(0) fixing append_hf, line 175
 0(0) xl_parse_format: parsing [P-hint: outbound alias
]
 0(0) xl_parse_format: format parsed OK: [1] items
 0(0) fixing lookup, line 181
 0(0) fixing sl_send_reply, line 182
 0(0) fixing append_hf, line 186
 0(0) xl_parse_format: parsing [P-hint: usrloc applied
]
 0(0) xl_parse_format: format parsed OK: [1] items
 0(0) fixing search, line 193
 0(0) module - fixing ^Route:
 0(0) fixing sl_send_reply, line 194
 0(0) fixing force_rtp_proxy, line 200
 0(0) fixing t_on_reply, line 206
 0(0) fixing t_relay, line 210
 0(0) fixing sl_reply_error, line 211
 0(0) fixing fix_nated_contact, line 219
 0(0) fixing force_rtp_proxy, line 220
 0(0) fixing nat_uac_test, line 223
 0(0) fixing fix_nated_contact, line 224
 0(0) INFO: udp_init: SO_RCVBUF is initially 109568
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 219136
 0(0) DEBUG: setting SO_RCVBUF; set=219136,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 221184
 0(0) DEBUG: setting SO_RCVBUF; set=221184,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 223232
 0(0) DEBUG: setting SO_RCVBUF; set=223232,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 225280
 0(0) DEBUG: setting SO_RCVBUF; set=225280,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 227328
 0(0) DEBUG: setting SO_RCVBUF; set=227328,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 229376
 0(0) DEBUG: setting SO_RCVBUF; set=229376,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 231424
 0(0) DEBUG: setting SO_RCVBUF; set=231424,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 233472
 0(0) DEBUG: setting SO_RCVBUF; set=233472,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 235520
 0(0) DEBUG: setting SO_RCVBUF; set=235520,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 237568
 0(0) DEBUG: setting SO_RCVBUF; set=237568,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 239616
 0(0) DEBUG: setting SO_RCVBUF; set=239616,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 241664
 0(0) DEBUG: setting SO_RCVBUF; set=241664,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 243712
 0(0) DEBUG: setting SO_RCVBUF; set=243712,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 245760
 0(0) DEBUG: setting SO_RCVBUF; set=245760,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 247808
 0(0) DEBUG: setting SO_RCVBUF; set=247808,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 249856
 0(0) DEBUG: setting SO_RCVBUF; set=249856,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 251904
 0(0) DEBUG: setting SO_RCVBUF; set=251904,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 253952
 0(0) DEBUG: setting SO_RCVBUF; set=253952,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 256000
 0(0) DEBUG: setting SO_RCVBUF; set=256000,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 258048
 0(0) DEBUG: setting SO_RCVBUF; set=258048,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 260096
 0(0) DEBUG: setting SO_RCVBUF; set=260096,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 262144
 0(0) DEBUG: setting SO_RCVBUF; set=262144,verify=262142
 0(0) DEBUG: setting SO_RCVBUF has no effect
 0(0) INFO: udp_init: SO_RCVBUF is finally 262142
 0(0) INFO: udp_init: SO_RCVBUF is initially 109568
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 219136
 0(0) DEBUG: setting SO_RCVBUF; set=219136,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 221184
 0(0) DEBUG: setting SO_RCVBUF; set=221184,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 223232
 0(0) DEBUG: setting SO_RCVBUF; set=223232,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 225280
 0(0) DEBUG: setting SO_RCVBUF; set=225280,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 227328
 0(0) DEBUG: setting SO_RCVBUF; set=227328,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 229376
 0(0) DEBUG: setting SO_RCVBUF; set=229376,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 231424
 0(0) DEBUG: setting SO_RCVBUF; set=231424,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 233472
 0(0) DEBUG: setting SO_RCVBUF; set=233472,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 235520
 0(0) DEBUG: setting SO_RCVBUF; set=235520,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 237568
 0(0) DEBUG: setting SO_RCVBUF; set=237568,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 239616
 0(0) DEBUG: setting SO_RCVBUF; set=239616,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 241664
 0(0) DEBUG: setting SO_RCVBUF; set=241664,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 243712
 0(0) DEBUG: setting SO_RCVBUF; set=243712,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 245760
 0(0) DEBUG: setting SO_RCVBUF; set=245760,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 247808
 0(0) DEBUG: setting SO_RCVBUF; set=247808,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 249856
 0(0) DEBUG: setting SO_RCVBUF; set=249856,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 251904
 0(0) DEBUG: setting SO_RCVBUF; set=251904,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 253952
 0(0) DEBUG: setting SO_RCVBUF; set=253952,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 256000
 0(0) DEBUG: setting SO_RCVBUF; set=256000,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 258048
 0(0) DEBUG: setting SO_RCVBUF; set=258048,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 260096
 0(0) DEBUG: setting SO_RCVBUF; set=260096,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 262144
 0(0) DEBUG: setting SO_RCVBUF; set=262144,verify=262142
 0(0) DEBUG: setting SO_RCVBUF has no effect
 0(0) INFO: udp_init: SO_RCVBUF is finally 262142
 0(0) INFO: udp_init: SO_RCVBUF is initially 109568
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 219136
 0(0) DEBUG: setting SO_RCVBUF; set=219136,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 221184
 0(0) DEBUG: setting SO_RCVBUF; set=221184,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 223232
 0(0) DEBUG: setting SO_RCVBUF; set=223232,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 225280
 0(0) DEBUG: setting SO_RCVBUF; set=225280,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 227328
 0(0) DEBUG: setting SO_RCVBUF; set=227328,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 229376
 0(0) DEBUG: setting SO_RCVBUF; set=229376,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 231424
 0(0) DEBUG: setting SO_RCVBUF; set=231424,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 233472
 0(0) DEBUG: setting SO_RCVBUF; set=233472,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 235520
 0(0) DEBUG: setting SO_RCVBUF; set=235520,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 237568
 0(0) DEBUG: setting SO_RCVBUF; set=237568,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 239616
 0(0) DEBUG: setting SO_RCVBUF; set=239616,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 241664
 0(0) DEBUG: setting SO_RCVBUF; set=241664,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 243712
 0(0) DEBUG: setting SO_RCVBUF; set=243712,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 245760
 0(0) DEBUG: setting SO_RCVBUF; set=245760,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 247808
 0(0) DEBUG: setting SO_RCVBUF; set=247808,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 249856
 0(0) DEBUG: setting SO_RCVBUF; set=249856,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 251904
 0(0) DEBUG: setting SO_RCVBUF; set=251904,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 253952
 0(0) DEBUG: setting SO_RCVBUF; set=253952,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 256000
 0(0) DEBUG: setting SO_RCVBUF; set=256000,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 258048
 0(0) DEBUG: setting SO_RCVBUF; set=258048,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 260096
 0(0) DEBUG: setting SO_RCVBUF; set=260096,verify=262142
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 262144
 0(0) DEBUG: setting SO_RCVBUF; set=262144,verify=262142
 0(0) DEBUG: setting SO_RCVBUF has no effect
 0(0) INFO: udp_init: SO_RCVBUF is finally 262142
 0(0) DBG: open_uac_fifo: opening fifo...
 0(0) DEBUG: FIFO created @ /tmp/ser_fifo
 0(0) DEBUG: fifo /tmp/ser_fifo opened, mode=432
 0(0) init_unixsock_socket: No unix domain socket will be opened
 1(8361) INFO: fifo process starting: 8361
 1(8361) DEBUG:init_mod_child: PROC_FIFO , rank=-2, module=tm
 1(8361) DEBUG: callid: '67d5ffff-8361@xxxxxxxxx'
 1(8361) DEBUG:init_mod_child: PROC_FIFO , rank=-2, module=usrloc
 1(8361) DEBUG:init_mod_child: PROC_FIFO , rank=-2, module=nathelper
 1(8361) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
 1(8361) INFO:open_uac_fifo: fifo server up at /tmp/ser_fifo...
 1(8361) DEBUG: register_fifo_cmd: new command (print) registered
 1(8361) DEBUG: register_fifo_cmd: new command (uptime) registered
 1(8361) DEBUG: register_fifo_cmd: new command (version) registered
 1(8361) DEBUG: register_fifo_cmd: new command (pwd) registered
 1(8361) DEBUG: register_fifo_cmd: new command (arg) registered
 1(8361) DEBUG: register_fifo_cmd: new command (which) registered
 1(8361) DEBUG: register_fifo_cmd: new command (ps) registered
 1(8361) DEBUG: register_fifo_cmd: new command (kill) registered
 1(8361) DEBUG: register_fifo_cmd: new command (meminfo) registered
 1(8361) INFO: no fifo_db_url given - fifo DB commands disabled!
 2(8362) DEBUG:init_mod_child: CHILD , rank=1, module=tm
 2(8362) DEBUG: callid: '67d5ffff-8362@xxxxxxxxx '
 2(8362) DEBUG:init_mod_child: CHILD , rank=1, module=usrloc
 2(8362) DEBUG:init_mod_child: CHILD , rank=1, module=nathelper
 3(8363) DEBUG:init_mod_child: CHILD , rank=2, module=tm
 3(8363) DEBUG: callid: ' 67d5ffff-8363@xxxxxxxxx'
 3(8363) DEBUG:init_mod_child: CHILD , rank=2, module=usrloc
 3(8363) DEBUG:init_mod_child: CHILD , rank=2, module=nathelper
 4(8364) DEBUG:init_mod_child: CHILD , rank=3, module=tm
 4(8364) DEBUG: callid: '67d5ffff-8364@xxxxxxxxx'
 4(8364) DEBUG:init_mod_child: CHILD , rank=3, module=usrloc
 4(8364) DEBUG:init_mod_child: CHILD , rank=3, module=nathelper
 5(8365) DEBUG:init_mod_child: CHILD , rank=4, module=tm
 5(8365) DEBUG: callid: '67d5ffff-8365@xxxxxxxxx'
 5(8365) DEBUG:init_mod_child: CHILD , rank=4, module=usrloc
 5(8365) DEBUG:init_mod_child: CHILD , rank=4, module=nathelper
 6(8366) DEBUG:init_mod_child: CHILD , rank=5, module=tm
 6(8366) DEBUG: callid: '67d5ffff-8366@xxxxxxxxxxxxx '
 6(8366) DEBUG:init_mod_child: CHILD , rank=5, module=usrloc
 6(8366) DEBUG:init_mod_child: CHILD , rank=5, module=nathelper
 7(8367) DEBUG:init_mod_child: CHILD , rank=6, module=tm
 7(8367) DEBUG: callid: ' 67d5ffff-8367@xxxxxxxxxxxxx'
 7(8367) DEBUG:init_mod_child: CHILD , rank=6, module=usrloc
 7(8367) DEBUG:init_mod_child: CHILD , rank=6, module=nathelper
 8(8368) DEBUG:init_mod_child: CHILD , rank=7, module=tm
 8(8368) DEBUG: callid: '67d5ffff-8368@xxxxxxxxxxxxx'
 8(8368) DEBUG:init_mod_child: CHILD , rank=7, module=usrloc
 8(8368) DEBUG:init_mod_child: CHILD , rank=7, module=nathelper
 9(8369) DEBUG:init_mod_child: CHILD , rank=8, module=tm
 9(8369) DEBUG: callid: '67d5ffff-8369@xxxxxxxxxxxxx'
 9(8369) DEBUG:init_mod_child: CHILD , rank=8, module=usrloc
 9(8369) DEBUG:init_mod_child: CHILD , rank=8, module=nathelper
10(8370) DEBUG:init_mod_child: CHILD , rank=9, module=tm
10(8370) DEBUG: callid: '67d5ffff-8370@xxxxxxxxxxxxxx '
10(8370) DEBUG:init_mod_child: CHILD , rank=9, module=usrloc
10(8370) DEBUG:init_mod_child: CHILD , rank=9, module=nathelper
11(8371) DEBUG:init_mod_child: CHILD , rank=10, module=tm
11(8371) DEBUG: callid: ' 67d5ffff-8371@xxxxxxxxxxxxxx'
11(8371) DEBUG:init_mod_child: CHILD , rank=10, module=usrloc
11(8371) DEBUG:init_mod_child: CHILD , rank=10, module=nathelper
12(8372) DEBUG:init_mod_child: CHILD , rank=11, module=tm
12(8372) DEBUG: callid: '67d5ffff-8372@xxxxxxxxxxxxxx'
12(8372) DEBUG:init_mod_child: CHILD , rank=11, module=usrloc
12(8372) DEBUG:init_mod_child: CHILD , rank=11, module=nathelper
13(8373) DEBUG:init_mod_child: CHILD , rank=12, module=tm
13(8373) DEBUG: callid: '67d5ffff-8373@xxxxxxxxxxxxxx'
13(8373) DEBUG:init_mod_child: CHILD , rank=12, module=usrloc
13(8373) DEBUG:init_mod_child: CHILD , rank=12, module=nathelper
14(8374) DEBUG:init_mod_child: PROC_TIMER , rank=-1, module=tm
14(8374) DEBUG: callid: '67d5ffff-8374@xxxxxxxxx '
14(8374) DEBUG:init_mod_child: PROC_TIMER , rank=-1, module=usrloc
14(8374) DEBUG:init_mod_child: PROC_TIMER , rank=-1, module=nathelper
15(8375) DEBUG:init_mod_child: CHILD , rank=13, module=tm
15(8375) DEBUG: callid: ' 67d5ffff-8375@xxxxxxxxx'
15(8375) DEBUG:init_mod_child: CHILD , rank=13, module=usrloc
15(8375) DEBUG:init_mod_child: CHILD , rank=13, module=nathelper
16(8376) DEBUG:init_mod_child: CHILD , rank=14, module=tm
16(8376) DEBUG: callid: '67d5ffff-8376@xxxxxxxxx'
16(8376) DEBUG:init_mod_child: CHILD , rank=14, module=usrloc
16(8376) DEBUG:init_mod_child: CHILD , rank=14, module=nathelper
17(8377) DEBUG:init_mod_child: CHILD , rank=15, module=tm
17(8377) DEBUG: callid: '67d5ffff-8377@xxxxxxxxx'
17(8377) DEBUG:init_mod_child: CHILD , rank=15, module=usrloc
17(8377) DEBUG:init_mod_child: CHILD , rank=15, module=nathelper
18(8378) DEBUG:init_mod_child: CHILD , rank=16, module=tm
18(8378) DEBUG: callid: '67d5ffff-8378@xxxxxxxxx '
18(8378) DEBUG:init_mod_child: CHILD , rank=16, module=usrloc
18(8378) DEBUG:init_mod_child: CHILD , rank=16, module=nathelper
19(8379) DEBUG:init_mod_child: PROC_TCP_MAIN , rank=-4, module=tm
19(8379) DEBUG: callid: ' 67d5ffff-8379@xxxxxxxxx'
19(8379) DEBUG:init_mod_child: PROC_TCP_MAIN , rank=-4, module=usrloc
19(8379) DEBUG:init_mod_child: PROC_TCP_MAIN , rank=-4, module=nathelper
 0(8360) DEBUG:init_mod_child: PROC_MAIN , rank=0, module=tm
 0(8360) DEBUG: callid: '67d5ffff-8360@xxxxxxxxx'
 0(8360) DEBUG:init_mod_child: PROC_MAIN , rank=0, module=usrloc
 0(8360) DEBUG:init_mod_child: PROC_MAIN , rank=0, module=nathelper
 2(8362) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
 3(8363) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
 4(8364) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
 5(8365) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
 6(8366) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
 7(8367) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
 8(8368) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
 9(8369) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
10(8370) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
11(8371) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
12(8372) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
13(8373) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
14(8374) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
15(8375) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
15(8375) DBG: io_watch_add(0x80dfe80, 29, 1, (nil)), fd_no=0
16(8376) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
16(8376) DBG: io_watch_add(0x80dfe80, 31, 1, (nil)), fd_no=0
17(8377) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
17(8377) DBG: io_watch_add(0x80dfe80, 33, 1, (nil)), fd_no=0
18(8378) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
18(8378) DBG: io_watch_add(0x80dfe80, 35, 1, (nil)), fd_no=0
19(8379) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
19(8379) DBG: io_watch_add(0x80dfd20, 7, 1, 0x8119550), fd_no=0
19(8379) DBG: io_watch_add(0x80dfd20, 8, 1, 0x81195e0), fd_no=1
19(8379) DBG: io_watch_add(0x80dfd20, 9, 1, 0x8119670), fd_no=2
19(8379) DBG: io_watch_add(0x80dfd20, 12, 4, 0xb5d45194), fd_no=3
19(8379) DBG: io_watch_add(0x80dfd20, 13, 4, 0xb5d45220), fd_no=4
19(8379) DBG: io_watch_add(0x80dfd20, 14, 4, 0xb5d452ac), fd_no=5
19(8379) DBG: io_watch_add(0x80dfd20, 15, 4, 0xb5d45338), fd_no=6
19(8379) DBG: io_watch_add(0x80dfd20, 16, 4, 0xb5d453c4), fd_no=7
19(8379) DBG: io_watch_add(0x80dfd20, 17, 4, 0xb5d45450), fd_no=8
19(8379) DBG: io_watch_add(0x80dfd20, 18, 4, 0xb5d454dc), fd_no=9
19(8379) DBG: io_watch_add(0x80dfd20, 19, 4, 0xb5d45568), fd_no=10
19(8379) DBG: io_watch_add(0x80dfd20, 20, 4, 0xb5d455f4), fd_no=11
19(8379) DBG: io_watch_add(0x80dfd20, 21, 4, 0xb5d45680), fd_no=12
19(8379) DBG: io_watch_add(0x80dfd20, 22, 4, 0xb5d4570c), fd_no=13
19(8379) DBG: io_watch_add(0x80dfd20, 23, 4, 0xb5d45798), fd_no=14
19(8379) DBG: io_watch_add(0x80dfd20, 24, 4, 0xb5d45824), fd_no=15
19(8379) DBG: io_watch_add(0x80dfd20, 25, 4, 0xb5d458b0), fd_no=16
19(8379) DBG: io_watch_add(0x80dfd20, 26, 4, 0xb5d4593c), fd_no=17
19(8379) DBG: io_watch_add(0x80dfd20, 27, 4, 0xb5d459c8), fd_no=18
19(8379) DBG: io_watch_add(0x80dfd20, 29, 4, 0xb5d45a54), fd_no=19
19(8379) DBG: io_watch_add(0x80dfd20, 31, 4, 0xb5d45ae0), fd_no=20
19(8379) DBG: io_watch_add(0x80dfd20, 28, 3, 0x8111300), fd_no=21
19(8379) DBG: io_watch_add(0x80dfd20, 30, 3, 0x8111314), fd_no=22
19(8379) DBG: io_watch_add(0x80dfd20, 32, 3, 0x8111328), fd_no=23
19(8379) DBG: io_watch_add(0x80dfd20, 34, 3, 0x811133c), fd_no=24
 0(8360) rtpp_test: RTP proxy <unix:/var/run/rtpproxy.sock> found, support for it enabled
10(8370) SIP Request:
10(8370)  method:  <REGISTER>
10(8370)  uri:     <sip: 169.198.11.110>
10(8370)  version: <SIP/2.0>
10(8370) parse_headers: flags=2
10(8370) get_hdr_field: cseq <CSeq>: <1> <REGISTER>
10(8370) Found param type 232, <branch> = <z9hG4bK7282f5f0-32ec-db11-9653-001372710463>; state=6
10(8370) Found param type 235, <rport> = <n/a>; state=17
10(8370) end of header reached, state=5
10(8370) parse_headers: Via found, flags=2
10(8370) parse_headers: this is the first via
10(8370) After parse_msg...
10(8370) preparing to run routing scripts...
10(8370) parse_headers: flags=100
10(8370) DEBUG:parse_to:end of header reached, state=10
10(8370) DBUG:parse_to: display={}, ruri={ sip:test@xxxxxxxxxxxxxx}
10(8370) DEBUG: get_hdr_field: <To> [27]; uri=[sip:test@xxxxxxxxxxxxxx]
10(8370) DEBUG: to body [< sip:test@xxxxxxxxxxxxxx>
]
10(8370) DEBUG: get_hdr_body : content_length=0
10(8370) DEBUG:maxfwd:is_maxfwd_present: value = 70
10(8370) check_via_address(169.198.11.19, 169.198.11.19, 0)
10(8370) parse_headers: flags=80
10(8370) parse_headers: flags=200
10(8370) found end of header
10(8370) find_first_route: No Route headers found
10(8370) loose_route: There is no Route HF
10(8370) grep_sock_info - checking if host==us: 14==9 &&  [169.198.11.110] == [127.0.0.1]
10(8370) grep_sock_info - checking if port 5060 matches port 5060
10(8370) grep_sock_info - checking if host==us: 14==13 &&  [169.198.11.110] == [169.198.11.95]
10(8370) grep_sock_info - checking if port 5060 matches port 5060
10(8370) grep_sock_info - checking if host==us: 14==14 &&  [169.198.11.110] == [169.198.11.110]
10(8370) grep_sock_info - checking if port 5060 matches port 5060
10(8370) grep_sock_info - checking if host==us: 14==9 &&  [169.198.11.110] == [127.0.0.1]
10(8370) grep_sock_info - checking if port 5060 matches port 5060
10(8370) grep_sock_info - checking if host==us: 14==13 &&  [169.198.11.110] == [169.198.11.95]
10(8370) grep_sock_info - checking if port 5060 matches port 5060
10(8370) grep_sock_info - checking if host==us: 14==14 &&  [169.198.11.110] == [169.198.11.110]
10(8370) grep_sock_info - checking if port 5060 matches port 5060
10(8370) parse_headers: flags=ffffffffffffffff
10(8370) parse_headers: flags=8000000
10(8370) parse_headers: flags=ffffffffffffffff
10(8370) build_contact(): Created Contact HF: Contact: <sip:test@xxxxxxxxxxxxx :5061;transport=udp>;expires=3600

10(8370) parse_headers: flags=ffffffffffffffff
10(8370) check_via_address(169.198.11.19, 169.198.11.19, 0)
10(8370) DEBUG:destroy_avp_list: destroying list (nil)
10(8370) receive_msg: cleaning up
12(8372) SIP Request:
12(8372)  method:  <SUBSCRIBE>
12(8372)  uri:     <sip:test@xxxxxxxxxxxxxx>
12(8372)  version: <SIP/2.0>
12(8372) parse_headers: flags=2
12(8372) get_hdr_field: cseq <CSeq>: <2> <SUBSCRIBE>
12(8372) Found param type 232, <branch> = <z9hG4bK225ef6f0-32ec-db11-9653-001372710463>; state=6
12(8372) Found param type 235, <rport> = <n/a>; state=17
12(8372) end of header reached, state=5
12(8372) parse_headers: Via found, flags=2
12(8372) parse_headers: this is the first via
12(8372) After parse_msg...
12(8372) preparing to run routing scripts...
12(8372) parse_headers: flags=100
12(8372) DEBUG:parse_to:end of header reached, state=10
12(8372) DBUG:parse_to: display={}, ruri={ sip:test@xxxxxxxxxxxxxx}
12(8372) DEBUG: get_hdr_field: <To> [27]; uri=[sip:test@xxxxxxxxxxxxxx]
12(8372) DEBUG: to body [< sip:test@xxxxxxxxxxxxxx>
]
12(8372) DEBUG: get_hdr_body : content_length=0
12(8372) DEBUG:maxfwd:is_maxfwd_present: value = 70
12(8372) check_via_address(169.198.11.19, 169.198.11.19, 0)
12(8372) parse_headers: flags=80
12(8372) DEBUG: add_param: tag=c457f6f0-32ec-db11-9653-001372710463
12(8372) DEBUG:parse_to:end of header reached, state=29
12(8372) DBUG:parse_to: display={}, ruri={ sip:test@xxxxxxxxxxxxxx}
12(8372) parse_headers: flags=200
12(8372) found end of header
12(8372) find_first_route: No Route headers found
12(8372) loose_route: There is no Route HF
12(8372) grep_sock_info - checking if host==us: 14==9 &&  [169.198.11.110] == [127.0.0.1]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) grep_sock_info - checking if host==us: 14==13 &&  [169.198.11.110] == [169.198.11.95]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) grep_sock_info - checking if host==us: 14==14 &&  [169.198.11.110] == [169.198.11.110]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) grep_sock_info - checking if host==us: 14==9 &&  [169.198.11.110] == [127.0.0.1]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) grep_sock_info - checking if host==us: 14==13 &&  [169.198.11.110] == [169.198.11.95]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) grep_sock_info - checking if host==us: 14==14 &&  [169.198.11.110] == [169.198.11.110]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) lookup(): 'test' Not found in usrloc
12(8372) grep_sock_info - checking if host==us: 14==9 &&  [169.198.11.110] == [127.0.0.1 ]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) grep_sock_info - checking if host==us: 14==13 &&  [169.198.11.110] == [ 169.198.11.95]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) grep_sock_info - checking if host==us: 14==14 &&  [169.198.11.110] == [ 169.198.11.110]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) rewrite_uri: Rewriting Request-URI with 'sip:test@xxxxxxxxxxxxx:5061;transport=udp'
12(8372) parse_headers: flags=ffffffffffffffff
12(8372) DEBUG: t_newtran: msg id=1 , global msg id=0 , T on entrance=0xffffffff
12(8372) parse_headers: flags=ffffffffffffffff
12(8372) parse_headers: flags=78
12(8372) t_lookup_request: start searching: hash=25492, isACK=0
12(8372) DEBUG: RFC3261 transaction matching failed
12(8372) DEBUG: t_lookup_request: no transaction found
12(8372) DEBUG: mk_proxy: doing DNS lookup...
12(8372) check_via_address( 169.198.11.19, 169.198.11.19, 0)
12(8372) DEBUG: add_to_tail_of_timer[4]: 0xb5ecaed4
12(8372) DEBUG: add_to_tail_of_timer[0]: 0xb5ecaee4
12(8372) SER: new transaction fwd'ed
12(8372) DEBUG:tm:UNREF_UNSAFE: after is 0
12(8372) DEBUG:destroy_avp_list: destroying list (nil)
12(8372) receive_msg: cleaning up
10(8370) SIP Reply  (status):
10(8370)  version: <SIP/2.0>
10(8370)  status:  <405>
10(8370)  reason:  <Method Not Allowed>
10(8370) parse_headers: flags=2
10(8370) get_hdr_field: cseq <CSeq>: <2> <SUBSCRIBE>
10(8370) Found param type 232, <branch> = <z9hG4bK4936.11151682.0 >; state=16
10(8370) end of header reached, state=5
10(8370) parse_headers: Via found, flags=2
10(8370) parse_headers: this is the first via
10(8370) After parse_msg...
10(8370) forward_reply: found module tm, passing reply to it
10(8370) DEBUG: t_check: msg id=2 global id=0 T start=0xffffffff
10(8370) parse_headers: flags=22
10(8370) DEBUG: t_reply_matching: hash 25492 label 677466385 branch 0
10(8370) DEBUG:tm:REF_UNSAFE: after is 1
10(8370) DEBUG: t_reply_matching: reply matched (T=0xb5ecadb8)!
10(8370) DEBUG: t_check: msg id=2 global id=2 T end=0xb5ecadb8
10(8370) DEBUG:tm:reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=0)
10(8370) parse_headers: flags=80
10(8370) Found param type 232, <branch> = <z9hG4bK225ef6f0-32ec-db11-9653-001372710463>; state=6
10(8370) Found param type 235, <rport> = <5062>; state=16
10(8370) end of header reached, state=5
10(8370) parse_headers: Via found, flags=80
10(8370) parse_headers: this is the second via
10(8370) DEBUG:parse_to:end of header reached, state=10
10(8370) DBUG:parse_to: display={}, ruri={ sip:test@xxxxxxxxxxxxxx}
10(8370) DEBUG: get_hdr_field: <To> [27]; uri=[sip:test@xxxxxxxxxxxxxx]
10(8370) DEBUG: to body [< sip:test@xxxxxxxxxxxxxx>
]
10(8370) DEBUG: get_hdr_body : content_length=0
10(8370) found end of header
10(8370) DEBUG:tm:t_should_relay_response: T_code=0, new_code=405
10(8370) DEBUG:tm:t_pick_branch: picked branch 0, code 405
10(8370) DEBUG:tm:relay_reply: branch=0, save=0, relay=0
10(8370)  old size: 494, new size: 431
10(8370) build_res_from_sip_res: copied size: orig:114, new: 51, rest: 380 msg=
SIP/2.0 405 Method Not Allowed
CSeq: 2 SUBSCRIBE
Via: SIP/2.0/UDP 169.198.11.19:5062;branch=z9hG4bK225ef6f0-32ec-db11-9653-001372710463;rport=5062
From: <sip:test@xxxxxxxxxxxxxx>;tag=c457f6f0-32ec-db11-9653-001372710463
Call-ID: 6a2af6f0-32ec-db11-9653-001372710463@maxedout
To: <sip:test@xxxxxxxxxxxxxx>
Allow: INVITE
Content-Length: 0
Record-Route: <sip:169.198.11.110;lr=on;ftag=c457f6f0-32ec-db11-9653-001372710463>
 

10(8370) WARNING:vqm_resize: resize(0) called
10(8370) DEBUG: add_to_tail_of_timer[2]: 0xb5ecae00
10(8370) DEBUG:tm:relay_reply: sent buf=0x8119dc8: SIP/2.0 4..., shmem=0xb5ecc7b8: SIP/2.0 4
10(8370) DEBUG: cleanup_uac_timers: RETR/FR timers reset
10(8370) DEBUG:tm:UNREF_UNSAFE: after is 0
10(8370) DEBUG:destroy_avp_list: destroying list (nil)
10(8370) receive_msg: cleaning up
14(8374) DEBUG: timer routine:0,tl=0xb5ecaee4 next=(nil)
14(8374) DEBUG: timer routine:4,tl=0xb5ecaed4 next=(nil)
14(8374) DEBUG: timer routine:2,tl=0xb5ecae00 next=(nil)
14(8374) DEBUG: wait_handler : removing 0xb5ecadb8 from table
14(8374) DEBUG: delete transaction 0xb5ecadb8
14(8374) DEBUG: wait_handler : done
12(8372) SIP Request:
12(8372)  method:  <REGISTER>
12(8372)  uri:     <sip:169.198.11.110>
12(8372)  version: <SIP/2.0>
12(8372) parse_headers: flags=2
12(8372) get_hdr_field: cseq <CSeq>: <1> <REGISTER>
12(8372) Found param type 232, <branch> = <z9hG4bK2c2fc8ec-75ec-db11-9c5e-00187185e000>; state=6
12(8372) Found param type 235, <rport> = <n/a>; state=17
12(8372) end of header reached, state=5
12(8372) parse_headers: Via found, flags=2
12(8372) parse_headers: this is the first via
12(8372) After parse_msg...
12(8372) preparing to run routing scripts...
12(8372) parse_headers: flags=100
12(8372) DEBUG:parse_to:end of header reached, state=10
12(8372) DBUG:parse_to: display={}, ruri={sip:test_store@xxxxxxxxxxxxxx}
12(8372) DEBUG: get_hdr_field: <To> [33]; uri=[ sip:test_store@xxxxxxxxxxxxxx]
12(8372) DEBUG: to body [<sip:test_store@xxxxxxxxxxxxxx>
]
12(8372) DEBUG: get_hdr_body : content_length=0
12(8372) DEBUG:maxfwd:is_maxfwd_present: value = 70
12(8372) check_via_address(169.198.11.175, 10.20.30.25, 0)
12(8372) LOG: Someone trying to register from private IP, rewriting
12(8372) parse_headers: flags=80
12(8372) parse_headers: flags=200
12(8372) found end of header
12(8372) find_first_route: No Route headers found
12(8372) loose_route: There is no Route HF
12(8372) grep_sock_info - checking if host==us: 14==9 &&  [169.198.11.110] == [127.0.0.1]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) grep_sock_info - checking if host==us: 14==13 &&  [169.198.11.110] == [169.198.11.95]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) grep_sock_info - checking if host==us: 14==14 &&  [169.198.11.110] == [169.198.11.110]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) grep_sock_info - checking if host==us: 14==9 &&  [169.198.11.110] == [127.0.0.1]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) grep_sock_info - checking if host==us: 14==13 &&  [169.198.11.110] == [169.198.11.95]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) grep_sock_info - checking if host==us: 14==14 &&  [169.198.11.110] == [169.198.11.110]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) parse_headers: flags=ffffffffffffffff
12(8372) parse_headers: flags=8000000
12(8372) parse_headers: flags=ffffffffffffffff
12(8372) build_contact(): Created Contact HF: Contact: <sip:test_store@xxxxxxxxxxxxxx :5061;transport=udp>;expires=3600

12(8372) parse_headers: flags=ffffffffffffffff
12(8372) check_via_address(169.198.11.175, 10.20.30.25, 0)
12(8372) DEBUG:destroy_avp_list: destroying list (nil)
12(8372) receive_msg: cleaning up
10(8370) SIP Request:
10(8370)  method:  <SUBSCRIBE>
10(8370)  uri:     <sip:test_store@xxxxxxxxxxxxxx>
10(8370)  version: <SIP/2.0>
10(8370) parse_headers: flags=2
10(8370) get_hdr_field: cseq <CSeq>: <2> <SUBSCRIBE>
10(8370) Found param type 232, <branch> = <z9hG4bKa4bac9ec-75ec-db11-9c5e-00187185e000>; state=6
10(8370) Found param type 235, <rport> = <n/a>; state=17
10(8370) end of header reached, state=5
10(8370) parse_headers: Via found, flags=2
10(8370) parse_headers: this is the first via
10(8370) After parse_msg...
10(8370) preparing to run routing scripts...
10(8370) parse_headers: flags=100
10(8370) DEBUG:parse_to:end of header reached, state=10
10(8370) DBUG:parse_to: display={}, ruri={ sip:test_store@xxxxxxxxxxxxxx}
10(8370) DEBUG: get_hdr_field: <To> [33]; uri=[sip:test_store@xxxxxxxxxxxxxx]
10(8370) DEBUG: to body [< sip:test_store@xxxxxxxxxxxxxx>
]
10(8370) DEBUG: get_hdr_body : content_length=0
10(8370) DEBUG:maxfwd:is_maxfwd_present: value = 70
10(8370) check_via_address(169.198.11.175, 10.20.30.25, 0)
10(8370) LOG: Someone trying to register from private IP, rewriting
10(8370) parse_headers: flags=80
10(8370) DEBUG: add_param: tag=96afc9ec-75ec-db11-9c5e-00187185e000
10(8370) DEBUG:parse_to:end of header reached, state=29
10(8370) DBUG:parse_to: display={}, ruri={sip:test_store@xxxxxxxxxxxxxx}
10(8370) parse_headers: flags=200
10(8370) found end of header
10(8370) find_first_route: No Route headers found
10(8370) loose_route: There is no Route HF
10(8370) grep_sock_info - checking if host==us: 14==9 &&  [169.198.11.110] == [127.0.0.1]
10(8370) grep_sock_info - checking if port 5060 matches port 5060
10(8370) grep_sock_info - checking if host==us: 14==13 &&  [169.198.11.110] == [169.198.11.95]
10(8370) grep_sock_info - checking if port 5060 matches port 5060
10(8370) grep_sock_info - checking if host==us: 14==14 &&  [169.198.11.110] == [169.198.11.110]
10(8370) grep_sock_info - checking if port 5060 matches port 5060
10(8370) grep_sock_info - checking if host==us: 14==9 &&  [169.198.11.110] == [127.0.0.1]
10(8370) grep_sock_info - checking if port 5060 matches port 5060
10(8370) grep_sock_info - checking if host==us: 14==13 &&  [169.198.11.110] == [169.198.11.95]
10(8370) grep_sock_info - checking if port 5060 matches port 5060
10(8370) grep_sock_info - checking if host==us: 14==14 &&  [169.198.11.110] == [169.198.11.110]
10(8370) grep_sock_info - checking if port 5060 matches port 5060
10(8370) lookup(): 'test_store' Not found in usrloc
10(8370) grep_sock_info - checking if host==us: 14==9 &&  [169.198.11.110] == [127.0.0.1 ]
10(8370) grep_sock_info - checking if port 5060 matches port 5060
10(8370) grep_sock_info - checking if host==us: 14==13 &&  [169.198.11.110] == [ 169.198.11.95]
10(8370) grep_sock_info - checking if port 5060 matches port 5060
10(8370) grep_sock_info - checking if host==us: 14==14 &&  [169.198.11.110] == [ 169.198.11.110]
10(8370) grep_sock_info - checking if port 5060 matches port 5060
10(8370) rewrite_uri: Rewriting Request-URI with 'sip:test_store@xxxxxxxxxxxxxx:5061;transport=udp'
10(8370) parse_headers: flags=ffffffffffffffff
10(8370) parse_headers: flags=ffffffffffffffff
10(8370) ERROR: extract_body: message body has length zero
10(8370) ERROR: force_rtp_proxy2: can't extract body from the message
10(8370) DEBUG: t_newtran: msg id=3 , global msg id=2 , T on entrance=0xffffffff
10(8370) parse_headers: flags=ffffffffffffffff
10(8370) parse_headers: flags=78
10(8370) t_lookup_request: start searching: hash=60390, isACK=0
10(8370) DEBUG: RFC3261 transaction matching failed
10(8370) DEBUG: t_lookup_request: no transaction found
10(8370) DEBUG: mk_proxy: doing DNS lookup...
10(8370) check_via_address(169.198.11.175, 10.20.30.25, 0)
10(8370) DEBUG: add_to_tail_of_timer[4]: 0xb5ecaed4
10(8370) DEBUG: add_to_tail_of_timer[0]: 0xb5ecaee4
10(8370) SER: new transaction fwd'ed
10(8370) DEBUG:tm:UNREF_UNSAFE: after is 0
10(8370) DEBUG:destroy_avp_list: destroying list (nil)
10(8370) receive_msg: cleaning up
12(8372) SIP Reply  (status):
12(8372)  version: <SIP/2.0>
12(8372)  status:  <405>
12(8372)  reason:  <Method Not Allowed>
12(8372) parse_headers: flags=2
12(8372) get_hdr_field: cseq <CSeq>: <2> <SUBSCRIBE>
12(8372) Found param type 232, <branch> = <z9hG4bK6ebe.5e66ab47.0>; state=16
12(8372) end of header reached, state=5
12(8372) parse_headers: Via found, flags=2
12(8372) parse_headers: this is the first via
12(8372) After parse_msg...
12(8372) forward_reply: found module tm, passing reply to it
12(8372) DEBUG: t_check: msg id=3 global id=1 T start=0xffffffff
12(8372) parse_headers: flags=22
12(8372) DEBUG: t_reply_matching: hash 60390 label 1958373093 branch 0
12(8372) DEBUG:tm:REF_UNSAFE: after is 1
12(8372) DEBUG: t_reply_matching: reply matched (T=0xb5ecadb8)!
12(8372) DEBUG: t_check: msg id=3 global id=3 T end=0xb5ecadb8
12(8372) DEBUG:tm:reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=0)
12(8372) parse_headers: flags=80
12(8372) Found param type 234, <received> = <169.198.11.175>; state=6
12(8372) Found param type 232, <branch> = <z9hG4bKa4bac9ec-75ec-db11-9c5e-00187185e000>; state=6
12(8372) Found param type 235, <rport> = <5062>; state=16
12(8372) end of header reached, state=5
12(8372) parse_headers: Via found, flags=80
12(8372) parse_headers: this is the second via
12(8372) DEBUG:parse_to:end of header reached, state=10
12(8372) DBUG:parse_to: display={}, ruri={sip:test_store@xxxxxxxxxxxxxx}
12(8372) DEBUG: get_hdr_field: <To> [33]; uri=[ sip:test_store@xxxxxxxxxxxxxx]
12(8372) DEBUG: to body [<sip:test_store@xxxxxxxxxxxxxx>
]
12(8372) DEBUG: get_hdr_body : content_length=0
12(8372) found end of header
12(8372) DEBUG:tm:t_should_relay_response: T_code=0, new_code=405
12(8372) DEBUG:tm:t_pick_branch: picked branch 0, code 405
12(8372) DEBUG:tm:relay_reply: branch=0, save=0, relay=0
12(8372)  old size: 531, new size: 468
12(8372) build_res_from_sip_res: copied size: orig:114, new: 51, rest: 417 msg=
SIP/2.0 405 Method Not Allowed
CSeq: 2 SUBSCRIBE
Via: SIP/2.0/UDP 10.20.30.25:5062;received=169.198.11.175;branch=z9hG4bKa4bac9ec-75ec-db11-9c5e-00187185e000;rport=5062
From: <sip:test_store@xxxxxxxxxxxxxx>;tag=96afc9ec-75ec-db11-9c5e-00187185e000
Call-ID: c841c9ec-75ec-db11-9c5e-00187185e000@xxxxxxxxxxx
To: <sip:test_store@xxxxxxxxxxxxxx>
Allow: INVITE
Content-Length: 0
Record-Route: <sip:169.198.11.110;lr=on;ftag=96afc9ec-75ec-db11-9c5e-00187185e000>
 

12(8372) WARNING:vqm_resize: resize(0) called
12(8372) DEBUG: add_to_tail_of_timer[2]: 0xb5ecae00
12(8372) DEBUG:tm:relay_reply: sent buf=0x811a760: SIP/2.0 4..., shmem=0xb5ecc4a8: SIP/2.0 4
12(8372) DEBUG: cleanup_uac_timers: RETR/FR timers reset
12(8372) DEBUG:tm:UNREF_UNSAFE: after is 0
12(8372) DEBUG:destroy_avp_list: destroying list (nil)
12(8372) receive_msg: cleaning up
14(8374) DEBUG: timer routine:0,tl=0xb5ecaee4 next=(nil)
14(8374) DEBUG: timer routine:4,tl=0xb5ecaed4 next=(nil)
14(8374) DEBUG: timer routine:2,tl=0xb5ecae00 next=(nil)
14(8374) DEBUG: wait_handler : removing 0xb5ecadb8 from table
14(8374) DEBUG: delete transaction 0xb5ecadb8
14(8374) DEBUG: wait_handler : done
11(8371) SIP Request:
11(8371)  method:  <INVITE>
11(8371)  uri:     <sip:test@xxxxxxxxxxxxxx>
11(8371)  version: <SIP/2.0>
11(8371) parse_headers: flags=2
11(8371) get_hdr_field: cseq <CSeq>: <1> <INVITE>
11(8371) Found param type 232, <branch> = <z9hG4bKd42631f8-75ec-db11-9c5e-00187185e000>; state=6
11(8371) Found param type 235, <rport> = <n/a>; state=17
11(8371) end of header reached, state=5
11(8371) parse_headers: Via found, flags=2
11(8371) parse_headers: this is the first via
11(8371) After parse_msg...
11(8371) preparing to run routing scripts...
11(8371) parse_headers: flags=100
11(8371) DEBUG:parse_to:end of header reached, state=10
11(8371) DBUG:parse_to: display={}, ruri={sip:test@xxxxxxxxxxxxxx}
11(8371) DEBUG: get_hdr_field: <To> [27]; uri=[sip:test@xxxxxxxxxxxxxx ]
11(8371) DEBUG: to body [<sip:test@xxxxxxxxxxxxxx>
]
11(8371) DEBUG: get_hdr_body : content_length=227
11(8371) DEBUG:maxfwd:is_maxfwd_present: value = 70
11(8371) check_via_address(169.198.11.175, 10.20.30.25, 0)
11(8371) LOG: Someone trying to register from private IP, rewriting
11(8371) parse_headers: flags=80
11(8371) parse_headers: flags=ffffffffffffffff
11(8371) found end of header
11(8371) DEBUG:check_content_type: type <application/sdp> found valid
11(8371) DEBUG: add_param: tag=fcbe2ff8-75ec-db11-9c5e-00187185e000
11(8371) DEBUG:parse_to:end of header reached, state=29
11(8371) DBUG:parse_to: display={"Test Store"}, ruri={ sip:test_store@xxxxxxxxxxxxxx}
11(8371) parse_headers: flags=200
11(8371) find_first_route: No Route headers found
11(8371) loose_route: There is no Route HF
11(8371) grep_sock_info - checking if host==us: 14==9 &&  [ 169.198.11.110] == [127.0.0.1]
11(8371) grep_sock_info - checking if port 5060 matches port 5060
11(8371) grep_sock_info - checking if host==us: 14==13 &&  [ 169.198.11.110] == [169.198.11.95]
11(8371) grep_sock_info - checking if port 5060 matches port 5060
11(8371) grep_sock_info - checking if host==us: 14==14 &&  [ 169.198.11.110] == [169.198.11.110]
11(8371) grep_sock_info - checking if port 5060 matches port 5060
11(8371) grep_sock_info - checking if host==us: 14==9 &&  [ 169.198.11.110] == [127.0.0.1]
11(8371) grep_sock_info - checking if port 5060 matches port 5060
11(8371) grep_sock_info - checking if host==us: 14==13 &&  [ 169.198.11.110] == [169.198.11.95]
11(8371) grep_sock_info - checking if port 5060 matches port 5060
11(8371) grep_sock_info - checking if host==us: 14==14 &&  [ 169.198.11.110] == [169.198.11.110]
11(8371) grep_sock_info - checking if port 5060 matches port 5060
11(8371) lookup(): 'test' Not found in usrloc
11(8371) grep_sock_info - checking if host==us: 14==9 &&  [169.198.11.110] == [127.0.0.1]
11(8371) grep_sock_info - checking if port 5060 matches port 5060
11(8371) grep_sock_info - checking if host==us: 14==13 &&  [169.198.11.110] == [169.198.11.95]
11(8371) grep_sock_info - checking if port 5060 matches port 5060
11(8371) grep_sock_info - checking if host==us: 14==14 &&  [169.198.11.110] == [169.198.11.110]
11(8371) grep_sock_info - checking if port 5060 matches port 5060
11(8371) rewrite_uri: Rewriting Request-URI with 'sip:test@xxxxxxxxxxxxx:5061;transport=udp'
11(8371) parse_headers: flags=ffffffffffffffff
11(8371) parse_headers: flags=ffffffffffffffff
11(8371) DEBUG:check_content_type: type <application/sdp> found valid
11(8371) parse_headers: flags=40
11(8371) force_rtp_proxy2: proxy reply: 35000 169.198.11.110

11(8371) force_rtp_proxy2: proxy reply: 35002 169.198.11.110

11(8371) DEBUG: t_newtran: msg id=1 , global msg id=0 , T on entrance=0xffffffff
11(8371) parse_headers: flags=ffffffffffffffff
11(8371) parse_headers: flags=78
11(8371) t_lookup_request: start searching: hash=64503, isACK=0
11(8371) DEBUG: RFC3261 transaction matching failed
11(8371) DEBUG: t_lookup_request: no transaction found
11(8371) DEBUG:tm:t_relay: new INVITE
11(8371) parse_headers: flags=ffffffffffffffff
11(8371) check_via_address( 169.198.11.175, 10.20.30.25, 0)
11(8371) WARNING:vqm_resize: resize(0) called
11(8371) DEBUG:tm:_reply_light: reply sent out. buf=0x811a7b8: SIP/2.0 1..., shmem=0xb5ecb8d0: SIP/2.0 1
11(8371) DEBUG:tm:_reply_light: finished
11(8371) DEBUG: mk_proxy: doing DNS lookup...
11(8371) parse_headers: flags=2000
11(8371) parse_headers: flags=ffffffffffffffff
11(8371) clen_builder: content-length: 270 (270)
11(8371) check_via_address(169.198.11.175, 10.20.30.25, 0)
11(8371) DEBUG: add_to_tail_of_timer[4]: 0xb5ecaed4
11(8371) DEBUG: add_to_tail_of_timer[0]: 0xb5ecaee4
11(8371) SER: new transaction fwd'ed
11(8371) DEBUG:tm:UNREF_UNSAFE: after is 0
11(8371) DEBUG:destroy_avp_list: destroying list (nil)
11(8371) receive_msg: cleaning up
10(8370) SIP Reply  (status):
10(8370)  version: <SIP/2.0>
10(8370)  status:  <100>
10(8370)  reason:  <Trying>
10(8370) parse_headers: flags=2
10(8370) get_hdr_field: cseq <CSeq>: <1> <INVITE>
10(8370) Found param type 232, <branch> = < z9hG4bK7fbf.981bd094.0>; state=16
10(8370) end of header reached, state=5
10(8370) parse_headers: Via found, flags=2
10(8370) parse_headers: this is the first via
10(8370) After parse_msg...
10(8370) forward_reply: found module tm, passing reply to it
10(8370) DEBUG: t_check: msg id=4 global id=3 T start=0xffffffff
10(8370) parse_headers: flags=22
10(8370) parse_headers: flags=8
10(8370) Found param type 234, <received> = < 169.198.11.175>; state=6
10(8370) Found param type 232, <branch> = <z9hG4bKd42631f8-75ec-db11-9c5e-00187185e000>; state=6
10(8370) Found param type 235, <rport> = <5063>; state=16
10(8370) end of header reached, state=5
10(8370) parse_headers: Via found, flags=8
10(8370) parse_headers: this is the second via
10(8370) DEBUG:parse_to:end of header reached, state=10
10(8370) DBUG:parse_to: display={}, ruri={ sip:test@xxxxxxxxxxxxxx}
10(8370) DEBUG: get_hdr_field: <To> [27]; uri=[sip:test@xxxxxxxxxxxxxx]
10(8370) DEBUG: to body [< sip:test@xxxxxxxxxxxxxx>
]
10(8370) DEBUG: t_reply_matching: hash 64503 label 1225634185 branch 0
10(8370) DEBUG:tm:REF_UNSAFE: after is 1
10(8370) DEBUG: t_reply_matching: reply matched (T=0xb5ecadb8)!
10(8370) DEBUG: t_check: msg id=4 global id=4 T end=0xb5ecadb8
10(8370) DEBUG:tm:reply_received: org. status uas=100, uac[0]=0 local=0 is_invite=1)
10(8370) parse_headers: flags=80
10(8370) DEBUG: get_hdr_body : content_length=0
10(8370) found end of header
10(8370) DEBUG:tm:t_should_relay_response: T_code=100, new_code=100
10(8370) DEBUG:tm:relay_reply: branch=0, save=0, relay=-1
10(8370) DEBUG: add_to_tail_of_timer[1]: 0xb5ecaee4
10(8370) DEBUG:tm:UNREF_UNSAFE: after is 0
10(8370) DEBUG:destroy_avp_list: destroying list (nil)
10(8370) receive_msg: cleaning up
12(8372) SIP Reply  (status):
12(8372)  version: <SIP/2.0>
12(8372)  status:  <100>
12(8372)  reason:  <Trying>
12(8372) parse_headers: flags=2
12(8372) get_hdr_field: cseq <CSeq>: <1> <INVITE>
12(8372) Found param type 232, <branch> = <z9hG4bK7fbf.981bd094.0>; state=16
12(8372) end of header reached, state=5
12(8372) parse_headers: Via found, flags=2
12(8372) parse_headers: this is the first via
12(8372) After parse_msg...
12(8372) forward_reply: found module tm, passing reply to it
12(8372) DEBUG: t_check: msg id=4 global id=3 T start=0xffffffff
12(8372) parse_headers: flags=22
12(8372) parse_headers: flags=8
12(8372) Found param type 234, <received> = <169.198.11.175>; state=6
12(8372) Found param type 232, <branch> = <z9hG4bKd42631f8-75ec-db11-9c5e-00187185e000>; state=6
12(8372) Found param type 235, <rport> = <5063>; state=16
12(8372) end of header reached, state=5
12(8372) parse_headers: Via found, flags=8
12(8372) parse_headers: this is the second via
12(8372) DEBUG: add_param: tag=8ed11bfa-33ec-db11-9653-001372710463
12(8372) DEBUG:parse_to:end of header reached, state=29
12(8372) DBUG:parse_to: display={}, ruri={sip:test@xxxxxxxxxxxxxx}
12(8372) DEBUG: get_hdr_field: <To> [68]; uri=[ sip:test@xxxxxxxxxxxxxx]
12(8372) DEBUG: to body [<sip:test@xxxxxxxxxxxxxx>]
12(8372) DEBUG: t_reply_matching: hash 64503 label 1225634185 branch 0
12(8372) DEBUG:tm:REF_UNSAFE: after is 1
12(8372) DEBUG: t_reply_matching: reply matched (T=0xb5ecadb8)!
12(8372) DEBUG: t_check: msg id=4 global id=4 T end=0xb5ecadb8
12(8372) DEBUG:tm:reply_received: org. status uas=100, uac[0]=100 local=0 is_invite=1)
12(8372) parse_headers: flags=80
12(8372) DEBUG: get_hdr_body : content_length=0
12(8372) found end of header
12(8372) DEBUG:tm:t_should_relay_response: T_code=100, new_code=100
12(8372) DEBUG:tm:relay_reply: branch=0, save=0, relay=-1
12(8372) DEBUG: add_to_tail_of_timer[1]: 0xb5ecaee4
12(8372) DEBUG:tm:UNREF_UNSAFE: after is 0
12(8372) DEBUG:destroy_avp_list: destroying list (nil)
12(8372) receive_msg: cleaning up
11(8371) SIP Reply  (status):
11(8371)  version: <SIP/2.0>
11(8371)  status:  <502>
11(8371)  reason:  <Bad Gateway>
11(8371) parse_headers: flags=2
11(8371) get_hdr_field: cseq <CSeq>: <1> <INVITE>
11(8371) Found param type 232, <branch> = <z9hG4bK7fbf.981bd094.0>; state=16
11(8371) end of header reached, state=5
11(8371) parse_headers: Via found, flags=2
11(8371) parse_headers: this is the first via
11(8371) After parse_msg...
11(8371) forward_reply: found module tm, passing reply to it
11(8371) DEBUG: t_check: msg id=2 global id=1 T start=0xffffffff
11(8371) parse_headers: flags=22
11(8371) parse_headers: flags=8
11(8371) Found param type 234, <received> = <169.198.11.175>; state=6
11(8371) Found param type 232, <branch> = <z9hG4bKd42631f8-75ec-db11-9c5e-00187185e000>; state=6
11(8371) Found param type 235, <rport> = <5063>; state=16
11(8371) end of header reached, state=5
11(8371) parse_headers: Via found, flags=8
11(8371) parse_headers: this is the second via
11(8371) DEBUG: add_param: tag=8ed11bfa-33ec-db11-9653-001372710463
11(8371) DEBUG:parse_to:end of header reached, state=29
11(8371) DBUG:parse_to: display={}, ruri={sip:test@xxxxxxxxxxxxxx}
11(8371) DEBUG: get_hdr_field: <To> [68]; uri=[ sip:test@xxxxxxxxxxxxxx]
11(8371) DEBUG: to body [<sip:test@xxxxxxxxxxxxxx>]
11(8371) DEBUG: t_reply_matching: hash 64503 label 1225634185 branch 0
11(8371) DEBUG:tm:REF_UNSAFE: after is 1
11(8371) DEBUG: t_reply_matching: reply matched (T=0xb5ecadb8)!
11(8371) DEBUG: t_check: msg id=2 global id=2 T end=0xb5ecadb8
11(8371) DEBUG:tm:reply_received: org. status uas=100, uac[0]=100 local=0 is_invite=1)
11(8371) parse_headers: flags=8
11(8371) DEBUG:tm:build_local: using FROM=<From: "Test Store" <sip:test_store@xxxxxxxxxxxxxx>;tag=fcbe2ff8-75ec-db11-9c5e-00187185e000
>, TO=<To: <sip:test@xxxxxxxxxxxxxx>;tag=8ed11bfa-33ec-db11-9653-001372710463
>, CSEQ_N=<CSeq: 1>
11(8371) parse_headers: flags=80
11(8371) DEBUG: get_hdr_body : content_length=0
11(8371) found end of header
11(8371) DEBUG:tm:t_should_relay_response: T_code=100, new_code=502
11(8371) DEBUG:tm:t_pick_branch: picked branch 0, code 502
11(8371) DEBUG:tm:relay_reply: branch=0, save=0, relay=0
11(8371)  old size: 613, new size: 550
11(8371) build_res_from_sip_res: copied size: orig:104, new: 41, rest: 509 msg=
SIP/2.0 502 Bad Gateway
CSeq: 1 INVITE
Via: SIP/2.0/UDP 10.20.30.25:5063;received=169.198.11.175;branch=z9hG4bKd42631f8-75ec-db11-9c5e-00187185e000;rport=5063
From: "Test Store" <sip:test_store@xxxxxxxxxxxxxx>;tag=fcbe2ff8-75ec-db11-9c5e-00187185e000
Call-ID: 14b12ff8-75ec-db11-9c5e-00187185e000@xxxxxxxxxxx
To: <sip:test@xxxxxxxxxxxxxx>;tag=8ed11bfa-33ec-db11-9653-001372710463
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,NOTIFY,REFER,MESSAGE
Content-Length: 0
Record-Route: <sip:169.198.11.110;lr=on;ftag=fcbe2ff8-75ec-db11-9c5e-00187185e000>
 

11(8371) DEBUG: add_to_tail_of_timer[4]: 0xb5ecae68
11(8371) DEBUG: add_to_tail_of_timer[0]: 0xb5ecae78
11(8371) DEBUG:tm:relay_reply: sent buf=0x811aac8: SIP/2.0 5..., shmem=0xb5ecc4a8: SIP/2.0 5
11(8371) DEBUG: cleanup_uac_timers: RETR/FR timers reset
11(8371) DEBUG:tm:UNREF_UNSAFE: after is 0
11(8371) DEBUG:destroy_avp_list: destroying list (nil)
11(8371) receive_msg: cleaning up
12(8372) SIP Request:
12(8372)  method:  <ACK>
12(8372)  uri:     < sip:test@xxxxxxxxxxxxxx>
12(8372)  version: <SIP/2.0>
12(8372) parse_headers: flags=2
12(8372) get_hdr_field: cseq <CSeq>: <1> <ACK>
12(8372) Found param type 232, <branch> = <z9hG4bKd42631f8-75ec-db11-9c5e-00187185e000>; state=6
12(8372) Found param type 235, <rport> = <n/a>; state=17
12(8372) end of header reached, state=5
12(8372) parse_headers: Via found, flags=2
12(8372) parse_headers: this is the first via
12(8372) After parse_msg...
12(8372) preparing to run routing scripts...
12(8372) DEBUG : sl_filter_ACK: to late to be a local ACK!
12(8372) parse_headers: flags=100
12(8372) DEBUG: add_param: tag=8ed11bfa-33ec-db11-9653-001372710463
12(8372) DEBUG:parse_to:end of header reached, state=29
12(8372) DBUG:parse_to: display={}, ruri={sip:test@xxxxxxxxxxxxxx}
12(8372) DEBUG: get_hdr_field: <To> [68]; uri=[ sip:test@xxxxxxxxxxxxxx]
12(8372) DEBUG: to body [<sip:test@xxxxxxxxxxxxxx>]
12(8372) DEBUG: get_hdr_body : content_length=0
12(8372) DEBUG:maxfwd:is_maxfwd_present: value = 70
12(8372) check_via_address(169.198.11.175, 10.20.30.25, 0)
12(8372) LOG: Someone trying to register from private IP, rewriting
12(8372) parse_headers: flags=80
12(8372) found end of header
12(8372) DEBUG: add_param: tag=fcbe2ff8-75ec-db11-9c5e-00187185e000
12(8372) DEBUG:parse_to:end of header reached, state=29
12(8372) DBUG:parse_to: display={"Test Store"}, ruri={ sip:test_store@xxxxxxxxxxxxxx}
12(8372) parse_headers: flags=200
12(8372) find_first_route: No Route headers found
12(8372) loose_route: There is no Route HF
12(8372) grep_sock_info - checking if host==us: 14==9 &&  [169.198.11.110] == [127.0.0.1]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) grep_sock_info - checking if host==us: 14==13 &&  [169.198.11.110] == [169.198.11.95]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) grep_sock_info - checking if host==us: 14==14 &&  [169.198.11.110] == [169.198.11.110]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) grep_sock_info - checking if host==us: 14==9 &&  [169.198.11.110] == [127.0.0.1]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) grep_sock_info - checking if host==us: 14==13 &&  [169.198.11.110] == [169.198.11.95]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) grep_sock_info - checking if host==us: 14==14 &&  [169.198.11.110] == [169.198.11.110]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) lookup(): 'test' Not found in usrloc
12(8372) grep_sock_info - checking if host==us: 14==9 &&  [169.198.11.110] == [127.0.0.1 ]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) grep_sock_info - checking if host==us: 14==13 &&  [169.198.11.110] == [ 169.198.11.95]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) grep_sock_info - checking if host==us: 14==14 &&  [169.198.11.110] == [ 169.198.11.110]
12(8372) grep_sock_info - checking if port 5060 matches port 5060
12(8372) rewrite_uri: Rewriting Request-URI with 'sip:test@xxxxxxxxxxxxx:5061;transport=udp'
12(8372) parse_headers: flags=ffffffffffffffff
12(8372) parse_headers: flags=ffffffffffffffff
12(8372) ERROR: extract_body: message body has length zero
12(8372) ERROR: force_rtp_proxy2: can't extract body from the message
12(8372) DEBUG: t_newtran: msg id=5 , global msg id=4 , T on entrance=0xffffffff
12(8372) parse_headers: flags=ffffffffffffffff
12(8372) parse_headers: flags=78
12(8372) t_lookup_request: start searching: hash=64503, isACK=1
12(8372) DEBUG: RFC3261 transaction matched, tid=d42631f8-75ec-db11-9c5e-00187185e000
12(8372) DEBUG:tm:REF_UNSAFE: after is 1
12(8372) DEBUG: t_lookup_request: transaction found (T=0xb5ecadb8)
12(8372) DEBUG: cleanup_uac_timers: RETR/FR timers reset
12(8372) DEBUG: add_to_tail_of_timer[2]: 0xb5ecae00
12(8372) DEBUG:tm:UNREF_UNSAFE: after is 0
12(8372) DEBUG:destroy_avp_list: destroying list (nil)
12(8372) receive_msg: cleaning up
14(8374) DEBUG: timer routine:0,tl=0xb5ecae78 next=(nil)
14(8374) DEBUG: timer routine:1,tl=0xb5ecaee4 next=(nil)
14(8374) DEBUG: timer routine:4,tl=0xb5ecae68 next=0xb5ecaed4
14(8374) DEBUG: timer routine:4,tl=0xb5ecaed4 next=(nil)
11(8371) SIP Reply  (status):
11(8371)  version: <SIP/2.0>
11(8371)  status:  <200>
11(8371)  reason:  <OK>
11(8371) parse_headers: flags=2
11(8371) get_hdr_field: cseq <CSeq>: <1> <INVITE>
11(8371) Found param type 232, <branch> = <z9hG4bK7fbf.981bd094.0>; state=16
11(8371) end of header reached, state=5
11(8371) parse_headers: Via found, flags=2
11(8371) parse_headers: this is the first via
11(8371) After parse_msg...
11(8371) forward_reply: found module tm, passing reply to it
11(8371) DEBUG: t_check: msg id=3 global id=2 T start=0xffffffff
11(8371) parse_headers: flags=22
11(8371) parse_headers: flags=8
11(8371) Found param type 234, <received> = < 169.198.11.175>; state=6
11(8371) Found param type 232, <branch> = <z9hG4bKd42631f8-75ec-db11-9c5e-00187185e000>; state=6
11(8371) Found param type 235, <rport> = <5063>; state=16
11(8371) end of header reached, state=5
11(8371) parse_headers: Via found, flags=8
11(8371) parse_headers: this is the second via
11(8371) DEBUG: add_param: tag=8ed11bfa-33ec-db11-9653-001372710463
11(8371) DEBUG:parse_to:end of header reached, state=29
11(8371) DBUG:parse_to: display={}, ruri={sip:test@xxxxxxxxxxxxxx}
11(8371) DEBUG: get_hdr_field: <To> [68]; uri=[sip:test@xxxxxxxxxxxxxx ]
11(8371) DEBUG: to body [<sip:test@xxxxxxxxxxxxxx>]
11(8371) DEBUG: t_reply_matching: hash 64503 label 1225634185 branch 0
11(8371) DEBUG:tm:REF_UNSAFE: after is 1
11(8371) DEBUG: t_reply_matching: reply matched (T=0xb5ecadb8)!
11(8371) DEBUG: t_check: msg id=3 global id=3 T end=0xb5ecadb8
11(8371) DEBUG:tm:reply_received: org. status uas=502, uac[0]=502 local=0 is_invite=1)
11(8371) parse_headers: flags=80
11(8371) parse_headers: flags=ffffffffffffffff
11(8371) DEBUG: get_hdr_body : content_length=153
11(8371) found end of header
11(8371) DEBUG:check_content_type: type <application/sdp> found valid
11(8371) parse_headers: flags=40
11(8371) DEBUG: add_param: tag=fcbe2ff8-75ec-db11-9c5e-00187185e000
11(8371) DEBUG:parse_to:end of header reached, state=29
11(8371) DBUG:parse_to: display={"Test Store"}, ruri={ sip:test_store@xxxxxxxxxxxxxx}
11(8371) force_rtp_proxy2: proxy reply: 35004 169.198.11.110

11(8371) DEBUG:tm:t_should_relay_response: T_code=502, new_code=200
11(8371) DEBUG:tm:t_should_relay_response: 200 OK for INVITE after final sent
11(8371) DEBUG:tm:relay_reply: branch=0, save=0, relay=0
11(8371) parse_headers: flags=2000
11(8371) parse_headers: flags=ffffffffffffffff
11(8371) clen_builder: content-length: 173 (173)
11(8371)  old size: 844, new size: 801
11(8371) build_res_from_sip_res: copied size: orig:844, new: 801, rest: 0 msg=
SIP/2.0 200 OK
CSeq: 1 INVITE
Via: SIP/2.0/UDP 10.20.30.25:5063;received=169.198.11.175;branch=z9hG4bKd42631f8-75ec-db11-9c5e-00187185e000;rport=5063
From: "Test Store" <sip:test_store@xxxxxxxxxxxxxx>;tag=fcbe2ff8-75ec-db11-9c5e-00187185e000
Call-ID: 14b12ff8-75ec-db11-9c5e-00187185e000@xxxxxxxxxxx
To: <sip:test@xxxxxxxxxxxxxx>;tag=8ed11bfa-33ec-db11-9653-001372710463
Contact: <sip:test@xxxxxxxxxxxxx:5063;transport=udp>
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,NOTIFY,REFER,MESSAGE
Content-Type: application/sdp
Content-Length: 173
Record-Route: <sip:169.198.11.110;lr=on;ftag=fcbe2ff8-75ec-db11-9c5e-00187185e000>
 
v=0
o=- 1176912192 1176912192 IN IP4 169.198.11.19
s=Opal SIP Session
c=IN IP4 169.198.11.110
t=0 0
m=video 35004 RTP/AVP 31
a=rtpmap:31 H261/90000
a=nortpproxy:yes

11(8371) DEBUG:tm:relay_reply: sent buf=0x811aac8: SIP/2.0 2..., shmem=0xb5ecb8d0: SIP/2.0 2
11(8371) DEBUG:tm:UNREF_UNSAFE: after is 0
11(8371) DEBUG:destroy_avp_list: destroying list (nil)
11(8371) receive_msg: cleaning up
14(8374) DEBUG: timer routine:2,tl=0xb5ecae00 next=(nil)
14(8374) DEBUG: wait_handler : removing 0xb5ecadb8 from table
14(8374) DEBUG: delete transaction 0xb5ecadb8
14(8374) DEBUG: wait_handler : done
10(8370) INFO: signal 15 received
10(8370) Memory status (pkg):
10(8370) fm_status (0x8111b00):
10(8370)  heap size= 1048576
10(8370)  used= 13648, used+overhead=32768, free=1015808
10(8370)  max used (+overhead)= 38536
10(8370) dumping free list:
10(8370) hash =   1 fragments no.:     5, unused:     0
         bucket size:         8 -         8 (first         8)
10(8370) hash =   2 fragments no.:     5, unused:     0
         bucket size:        16 -        16 (first        16)
10(8370) hash =   3 fragments no.:     5, unused:     0
         bucket size:        24 -        24 (first        24)
10(8370) hash =   4 fragments no.:    28, unused:     0
         bucket size:        32 -        32 (first        32)
10(8370) hash =   5 fragments no.:     8, unused:     0
         bucket size:        40 -        40 (first        40)
10(8370) hash =   6 fragments no.:     8, unused:     0
         bucket size:        48 -        48 (first        48)
10(8370) hash =   7 fragments no.:     2, unused:     0
         bucket size:        56 -        56 (first        56)
10(8370) hash =   8 fragments no.:     3, unused:     0
         bucket size:        64 -        64 (first        64)
10(8370) hash =   9 fragments no.:     2, unused:     0
         bucket size:        72 -        72 (first        72)
10(8370) hash =  10 fragments no.:     2, unused:     0
         bucket size:        80 -        80 (first        80)
10(8370) hash =  15 fragments no.:     2, unused:     0
         bucket size:       120 -       120 (first       120)
10(8370) hash =  87 fragments no.:     1, unused:     0
         bucket size:       696 -       696 (first       696)
10(8370) hash =  99 fragments no.:     1, unused:     0
         bucket size:       792 -       792 (first       792)
10(8370) hash = 447 fragments no.:     1, unused:     0
         bucket size:      3576 -      3576 (first      3576)
10(8370) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first   1008056)
10(8370) TOTAL:     74 free fragments = 1015808 free bytes
10(8370) -----------------------------
19(8379) ERROR: receive_fd: EOF on 21
19(8379) DBG: handle_ser_child: dead child 10, pid 8370 (shutting down?)
19(8379) DBG: io_watch_del (0x80dfd20, 21, -1, 0x0) fd_no=25 called
12(8372) INFO: signal 15 received
12(8372) Memory status (pkg):
12(8372) fm_status (0x8111b00):
12(8372)  heap size= 1048576
12(8372)  used= 13616, used+overhead=32696, free=1015880
12(8372)  max used (+overhead)= 38536
12(8372) dumping free list:
12(8372) hash =   1 fragments no.:     8, unused:     0
         bucket size:         8 -         8 (first         8)
12(8372) hash =   2 fragments no.:     2, unused:     0
         bucket size:        16 -        16 (first        16)
12(8372) hash =   3 fragments no.:     5, unused:     0
         bucket size:        24 -        24 (first        24)
12(8372) hash =   4 fragments no.:    24, unused:     0
         bucket size:        32 -        32 (first        32)
12(8372) hash =   5 fragments no.:     8, unused:     0
         bucket size:        40 -        40 (first        40)
12(8372) hash =   6 fragments no.:     7, unused:     0
         bucket size:        48 -        48 (first        48)
12(8372) hash =   7 fragments no.:     1, unused:     0
         bucket size:        56 -        56 (first        56)
12(8372) hash =   8 fragments no.:     1, unused:     0
         bucket size:        64 -        64 (first        64)
12(8372) hash =   9 fragments no.:     2, unused:     0
         bucket size:        72 -        72 (first        72)
12(8372) hash =  10 fragments no.:     4, unused:     0
         bucket size:        80 -        80 (first        80)
12(8372) hash =  15 fragments no.:     1, unused:     0
         bucket size:       120 -       120 (first       120)
12(8372) hash =  16 fragments no.:     1, unused:     0
         bucket size:       128 -       128 (first       128)
12(8372) hash =  68 fragments no.:     1, unused:     0
         bucket size:       544 -       544 (first       544)
12(8372) hash =  87 fragments no.:     1, unused:     0
         bucket size:       696 -       696 (first       696)
12(8372) hash =  99 fragments no.:     1, unused:     0
         bucket size:       792 -       792 (first       792)
12(8372) hash = 415 fragments no.:     1, unused:     0
         bucket size:      3320 -      3320 (first      3320)
12(8372) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first   1008056)
12(8372) TOTAL:     69 free fragments = 1015880 free bytes
12(8372) -----------------------------
19(8379) ERROR: receive_fd: EOF on 23
19(8379) DBG: handle_ser_child: dead child 12, pid 8372 (shutting down?)
19(8379) DBG: io_watch_del (0x80dfd20, 23, -1, 0x0) fd_no=24 called
14(8374) INFO: signal 15 received
14(8374) Memory status (pkg):
14(8374) fm_status (0x8111b00):
14(8374)  heap size= 1048576
14(8374)  used= 13488, used+overhead=32112, free=1016464
14(8374)  max used (+overhead)= 38536
14(8374) dumping free list:
14(8374) hash =   1 fragments no.:     1, unused:     0
         bucket size:         8 -         8 (first         8)
14(8374) hash =   9 fragments no.:     1, unused:     0
         bucket size:        72 -        72 (first        72)
14(8374) hash =  16 fragments no.:     9, unused:     0
         bucket size:       128 -       128 (first       128)
14(8374) hash =  97 fragments no.:     1, unused:     0
         bucket size:       776 -       776 (first       776)
14(8374) hash = 800 fragments no.:     1, unused:     0
         bucket size:      6400 -      6400 (first      6400)
14(8374) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first   1008056)
14(8374) TOTAL:     14 free fragments = 1016464 free bytes
14(8374) -----------------------------
19(8379) ERROR: receive_fd: EOF on 25
19(8379) DBG: handle_ser_child: dead child 14, pid 8374 (shutting down?)
19(8379) DBG: io_watch_del (0x80dfd20, 25, -1, 0x0) fd_no=23 called
19(8379) INFO: signal 15 received
19(8379) Memory status (pkg):
19(8379) fm_status (0x8111b00):
19(8379)  heap size= 1048576
19(8379)  used= 63728, used+overhead=82360, free=966216
19(8379)  max used (+overhead)= 82360
19(8379) dumping free list:
19(8379) hash =  11 fragments no.:     1, unused:     0
         bucket size:        88 -        88 (first        88)
19(8379) hash =  16 fragments no.:     9, unused:     0
         bucket size:       128 -       128 (first       128)
19(8379) hash =  97 fragments no.:     1, unused:     0
         bucket size:       776 -       776 (first       776)
19(8379) hash = 800 fragments no.:     1, unused:     0
         bucket size:      6400 -      6400 (first      6400)
19(8379) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first    957800)
19(8379) TOTAL:     13 free fragments = 966216 free bytes
19(8379) -----------------------------
 0(8360) child process 8370 exited normally, status=0
 0(8360) child process 8372 exited normally, status=0
 0(8360) child process 8374 exited normally, status=0
 0(8360) child process 8379 exited normally, status=0
 0(8360) INFO: terminating due to SIGCHLD
 1(8361) INFO: signal 15 received
 1(8361) Memory status (pkg):
 1(8361) fm_status (0x8111b00):
 1(8361)  heap size= 1048576
 1(8361)  used= 13648, used+overhead=32320, free=1016256
 1(8361)  max used (+overhead)= 38536
 1(8361) dumping free list:
 1(8361) hash =  16 fragments no.:     8, unused:     0
         bucket size:       128 -       128 (first       128)
 1(8361) hash =  97 fragments no.:     1, unused:     0
         bucket size:       776 -       776 (first       776)
 1(8361) hash = 800 fragments no.:     1, unused:     0
         bucket size:      6400 -      6400 (first      6400)
 1(8361) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first   1008056)
 1(8361) TOTAL:     11 free fragments = 1016256 free bytes
 1(8361) -----------------------------
 2(8362) INFO: signal 15 received
 2(8362) Memory status (pkg):
 2(8362) fm_status (0x8111b00):
 2(8362)  heap size= 1048576
 2(8362)  used= 13520, used+overhead=32144, free=1016432
 2(8362)  max used (+overhead)= 38536
 2(8362) dumping free list:
 2(8362) hash =   6 fragments no.:     1, unused:     0
         bucket size:        48 -        48 (first        48)
 2(8362) hash =  16 fragments no.:     9, unused:     0
         bucket size:       128 -       128 (first       128)
 2(8362) hash =  97 fragments no.:     1, unused:     0
         bucket size:       776 -       776 (first       776)
 2(8362) hash = 800 fragments no.:     1, unused:     0
         bucket size:      6400 -      6400 (first      6400)
 2(8362) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first   1008056)
 2(8362) TOTAL:     13 free fragments = 1016432 free bytes
 2(8362) -----------------------------
 3(8363) INFO: signal 15 received
 3(8363) Memory status (pkg):
 3(8363) fm_status (0x8111b00):
 3(8363)  heap size= 1048576
 3(8363)  used= 13520, used+overhead=32144, free=1016432
 3(8363)  max used (+overhead)= 38536
 3(8363) dumping free list:
 3(8363) hash =   6 fragments no.:     1, unused:     0
         bucket size:        48 -        48 (first        48)
 3(8363) hash =  16 fragments no.:     9, unused:     0
         bucket size:       128 -       128 (first       128)
 3(8363) hash =  97 fragments no.:     1, unused:     0
         bucket size:       776 -       776 (first       776)
 3(8363) hash = 800 fragments no.:     1, unused:     0
         bucket size:      6400 -      6400 (first      6400)
 3(8363) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first   1008056)
 3(8363) TOTAL:     13 free fragments = 1016432 free bytes
 3(8363) -----------------------------
 4(8364) INFO: signal 15 received
 4(8364) Memory status (pkg):
 4(8364) fm_status (0x8111b00):
 4(8364)  heap size= 1048576
 4(8364)  used= 13520, used+overhead=32144, free=1016432
 4(8364)  max used (+overhead)= 38536
 4(8364) dumping free list:
 4(8364) hash =   6 fragments no.:     1, unused:     0
         bucket size:        48 -        48 (first        48)
 4(8364) hash =  16 fragments no.:     9, unused:     0
         bucket size:       128 -       128 (first       128)
 4(8364) hash =  97 fragments no.:     1, unused:     0
         bucket size:       776 -       776 (first       776)
 4(8364) hash = 800 fragments no.:     1, unused:     0
         bucket size:      6400 -      6400 (first      6400)
 4(8364) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first   1008056)
 4(8364) TOTAL:     13 free fragments = 1016432 free bytes
 4(8364) -----------------------------
 5(8365) INFO: signal 15 received
 5(8365) Memory status (pkg):
 5(8365) fm_status (0x8111b00):
 5(8365)  heap size= 1048576
 5(8365)  used= 13520, used+overhead=32144, free=1016432
 5(8365)  max used (+overhead)= 38536
 5(8365) dumping free list:
 5(8365) hash =   6 fragments no.:     1, unused:     0
         bucket size:        48 -        48 (first        48)
 5(8365) hash =  16 fragments no.:     9, unused:     0
         bucket size:       128 -       128 (first       128)
 5(8365) hash =  97 fragments no.:     1, unused:     0
         bucket size:       776 -       776 (first       776)
 5(8365) hash = 800 fragments no.:     1, unused:     0
         bucket size:      6400 -      6400 (first      6400)
 5(8365) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first   1008056)
 5(8365) TOTAL:     13 free fragments = 1016432 free bytes
 5(8365) -----------------------------
 6(8366) INFO: signal 15 received
 6(8366) Memory status (pkg):
 6(8366) fm_status (0x8111b00):
 6(8366)  heap size= 1048576
 6(8366)  used= 13520, used+overhead=32144, free=1016432
 6(8366)  max used (+overhead)= 38536
 6(8366) dumping free list:
 6(8366) hash =   6 fragments no.:     1, unused:     0
         bucket size:        48 -        48 (first        48)
 6(8366) hash =  16 fragments no.:     9, unused:     0
         bucket size:       128 -       128 (first       128)
 6(8366) hash =  97 fragments no.:     1, unused:     0
         bucket size:       776 -       776 (first       776)
 6(8366) hash = 800 fragments no.:     1, unused:     0
         bucket size:      6400 -      6400 (first      6400)
 6(8366) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first   1008056)
 6(8366) TOTAL:     13 free fragments = 1016432 free bytes
 6(8366) -----------------------------
 7(8367) INFO: signal 15 received
 7(8367) Memory status (pkg):
 7(8367) fm_status (0x8111b00):
 7(8367)  heap size= 1048576
 7(8367)  used= 13520, used+overhead=32144, free=1016432
 7(8367)  max used (+overhead)= 38536
 7(8367) dumping free list:
 7(8367) hash =   6 fragments no.:     1, unused:     0
         bucket size:        48 -        48 (first        48)
 7(8367) hash =  16 fragments no.:     9, unused:     0
         bucket size:       128 -       128 (first       128)
 7(8367) hash =  97 fragments no.:     1, unused:     0
         bucket size:       776 -       776 (first       776)
 7(8367) hash = 800 fragments no.:     1, unused:     0
         bucket size:      6400 -      6400 (first      6400)
 7(8367) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first   1008056)
 7(8367) TOTAL:     13 free fragments = 1016432 free bytes
 7(8367) -----------------------------
 8(8368) INFO: signal 15 received
 8(8368) Memory status (pkg):
 8(8368) fm_status (0x8111b00):
 8(8368)  heap size= 1048576
 8(8368)  used= 13520, used+overhead=32144, free=1016432
 8(8368)  max used (+overhead)= 38536
 8(8368) dumping free list:
 8(8368) hash =   6 fragments no.:     1, unused:     0
         bucket size:        48 -        48 (first        48)
 8(8368) hash =  16 fragments no.:     9, unused:     0
         bucket size:       128 -       128 (first       128)
 8(8368) hash =  97 fragments no.:     1, unused:     0
         bucket size:       776 -       776 (first       776)
 8(8368) hash = 800 fragments no.:     1, unused:     0
         bucket size:      6400 -      6400 (first      6400)
 8(8368) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first   1008056)
 8(8368) TOTAL:     13 free fragments = 1016432 free bytes
 8(8368) -----------------------------
 9(8369) INFO: signal 15 received
 9(8369) Memory status (pkg):
 9(8369) fm_status (0x8111b00):
 9(8369)  heap size= 1048576
 9(8369)  used= 13520, used+overhead=32144, free=1016432
 9(8369)  max used (+overhead)= 38536
 9(8369) dumping free list:
 9(8369) hash =   6 fragments no.:     1, unused:     0
         bucket size:        48 -        48 (first        48)
 9(8369) hash =  16 fragments no.:     9, unused:     0
         bucket size:       128 -       128 (first       128)
 9(8369) hash =  97 fragments no.:     1, unused:     0
         bucket size:       776 -       776 (first       776)
 9(8369) hash = 800 fragments no.:     1, unused:     0
         bucket size:      6400 -      6400 (first      6400)
 9(8369) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first   1008056)
 9(8369) TOTAL:     13 free fragments = 1016432 free bytes
 9(8369) -----------------------------
15(8375) INFO: signal 15 received
15(8375) Memory status (pkg):
15(8375) fm_status (0x8111b00):
15(8375)  heap size= 1048576
15(8375)  used= 63728, used+overhead=82360, free=966216
15(8375)  max used (+overhead)= 82360
15(8375) dumping free list:
15(8375) hash =  11 fragments no.:     1, unused:     0
         bucket size:        88 -        88 (first        88)
15(8375) hash =  16 fragments no.:     9, unused:     0
         bucket size:       128 -       128 (first       128)
15(8375) hash =  97 fragments no.:     1, unused:     0
         bucket size:       776 -       776 (first       776)
15(8375) hash = 800 fragments no.:     1, unused:     0
         bucket size:      6400 -      6400 (first      6400)
15(8375) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first    957800)
15(8375) TOTAL:     13 free fragments = 966216 free bytes
15(8375) -----------------------------
16(8376) INFO: signal 15 received
16(8376) Memory status (pkg):
16(8376) fm_status (0x8111b00):
16(8376)  heap size= 1048576
16(8376)  used= 63728, used+overhead=82360, free=966216
16(8376)  max used (+overhead)= 82360
16(8376) dumping free list:
16(8376) hash =  11 fragments no.:     1, unused:     0
         bucket size:        88 -        88 (first        88)
16(8376) hash =  16 fragments no.:     9, unused:     0
         bucket size:       128 -       128 (first       128)
16(8376) hash =  97 fragments no.:     1, unused:     0
         bucket size:       776 -       776 (first       776)
16(8376) hash = 800 fragments no.:     1, unused:     0
         bucket size:      6400 -      6400 (first      6400)
16(8376) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first    957800)
16(8376) TOTAL:     13 free fragments = 966216 free bytes
16(8376) -----------------------------
17(8377) INFO: signal 15 received
17(8377) Memory status (pkg):
17(8377) fm_status (0x8111b00):
17(8377)  heap size= 1048576
17(8377)  used= 63728, used+overhead=82360, free=966216
17(8377)  max used (+overhead)= 82360
17(8377) dumping free list:
17(8377) hash =  11 fragments no.:     1, unused:     0
         bucket size:        88 -        88 (first        88)
17(8377) hash =  16 fragments no.:     9, unused:     0
         bucket size:       128 -       128 (first       128)
17(8377) hash =  97 fragments no.:     1, unused:     0
         bucket size:       776 -       776 (first       776)
17(8377) hash = 800 fragments no.:     1, unused:     0
         bucket size:      6400 -      6400 (first      6400)
17(8377) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first    957800)
17(8377) TOTAL:     13 free fragments = 966216 free bytes
17(8377) -----------------------------
18(8378) INFO: signal 15 received
18(8378) Memory status (pkg):
18(8378) fm_status (0x8111b00):
18(8378)  heap size= 1048576
18(8378)  used= 63728, used+overhead=82360, free=966216
18(8378)  max used (+overhead)= 82360
18(8378) dumping free list:
18(8378) hash =  11 fragments no.:     1, unused:     0
         bucket size:        88 -        88 (first        88)
18(8378) hash =  16 fragments no.:     9, unused:     0
         bucket size:       128 -       128 (first       128)
18(8378) hash =  97 fragments no.:     1, unused:     0
         bucket size:       776 -       776 (first       776)
18(8378) hash = 800 fragments no.:     1, unused:     0
         bucket size:      6400 -      6400 (first      6400)
18(8378) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first    957800)
18(8378) TOTAL:     13 free fragments = 966216 free bytes
18(8378) -----------------------------
11(8371) INFO: signal 15 received
11(8371) Memory status (pkg):
11(8371) fm_status (0x8111b00):
11(8371)  heap size= 1048576
11(8371)  used= 13520, used+overhead=32776, free=1015800
11(8371)  max used (+overhead)= 38536
11(8371) dumping free list:
11(8371) hash =   1 fragments no.:    10, unused:     0
         bucket size:         8 -         8 (first         8)
11(8371) hash =   2 fragments no.:     3, unused:     0
         bucket size:        16 -        16 (first        16)
11(8371) hash =   3 fragments no.:     8, unused:     0
         bucket size:        24 -        24 (first        24)
11(8371) hash =   4 fragments no.:    40, unused:     0
         bucket size:        32 -        32 (first        32)
11(8371) hash =   5 fragments no.:     7, unused:     0
         bucket size:        40 -        40 (first        40)
11(8371) hash =   6 fragments no.:     8, unused:     0
         bucket size:        48 -        48 (first        48)
11(8371) hash =   8 fragments no.:     3, unused:     0
         bucket size:        64 -        64 (first        64)
11(8371) hash =   9 fragments no.:     2, unused:     0
         bucket size:        72 -        72 (first        72)
11(8371) hash =  10 fragments no.:     4, unused:     0
         bucket size:        80 -        80 (first        80)
11(8371) hash =  11 fragments no.:     1, unused:     0
         bucket size:        88 -        88 (first        88)
11(8371) hash =  15 fragments no.:     1, unused:     0
         bucket size:       120 -       120 (first       120)
11(8371) hash =  16 fragments no.:     1, unused:     0
         bucket size:       128 -       128 (first       128)
11(8371) hash =  99 fragments no.:     1, unused:     0
         bucket size:       792 -       792 (first       792)
11(8371) hash = 119 fragments no.:     1, unused:     0
         bucket size:       952 -       952 (first       952)
11(8371) hash = 343 fragments no.:     1, unused:     0
         bucket size:      2744 -      2744 (first      2744)
11(8371) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first   1008056)
11(8371) TOTAL:     92 free fragments = 1015800 free bytes
11(8371) -----------------------------
13(8373) INFO: signal 15 received
13(8373) Memory status (pkg):
13(8373) fm_status (0x8111b00):
13(8373)  heap size= 1048576
13(8373)  used= 13520, used+overhead=32144, free=1016432
13(8373)  max used (+overhead)= 38536
13(8373) dumping free list:
13(8373) hash =   6 fragments no.:     1, unused:     0
         bucket size:        48 -        48 (first        48)
13(8373) hash =  16 fragments no.:     9, unused:     0
         bucket size:       128 -       128 (first       128)
13(8373) hash =  97 fragments no.:     1, unused:     0
         bucket size:       776 -       776 (first       776)
13(8373) hash = 800 fragments no.:     1, unused:     0
         bucket size:      6400 -      6400 (first      6400)
13(8373) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first   1008056)
13(8373) TOTAL:     13 free fragments = 1016432 free bytes
13(8373) -----------------------------
 0(8360) DEBUG: tm_shutdown : start
 0(8360) DEBUG: unlink_timer_lists : emptying DELETE list
 0(8360) DEBUG: tm_shutdown : emptying hash table
 0(8360) DEBUG: tm_shutdown : releasing timers
 0(8360) DEBUG: tm_shutdown : removing semaphores
 0(8360) DEBUG: tm_shutdown : destroying tmcb lists
 0(8360) DEBUG: tm_shutdown : done
 0(8360) Memory status (pkg):
 0(8360) fm_status (0x8111b00):
 0(8360)  heap size= 1048576
 0(8360)  used= 12888, used+overhead=31504, free=1017072
 0(8360)  max used (+overhead)= 38536
 0(8360) dumping free list:
 0(8360) hash =   2 fragments no.:    33, unused:     0
         bucket size:        16 -        16 (first        16)
 0(8360) hash =   3 fragments no.:     3, unused:     0
         bucket size:        24 -        24 (first        24)
 0(8360) hash =  11 fragments no.:     1, unused:     0
         bucket size:        88 -        88 (first        88)
 0(8360) hash =  16 fragments no.:     9, unused:     0
         bucket size:       128 -       128 (first       128)
 0(8360) hash =  97 fragments no.:     1, unused:     0
         bucket size:       776 -       776 (first       776)
 0(8360) hash = 800 fragments no.:     1, unused:     0
         bucket size:      6400 -      6400 (first      6400)
 0(8360) hash = 2054 fragments no.:     1, unused:     0
         bucket size:    524288 -   1048576 (first   1008056)
 0(8360) TOTAL:     49 free fragments = 1017072 free bytes
 0(8360) -----------------------------
 0(8360) Memory status (shm):
 0(8360) fm_status (0xb5d3f000):
 0(8360)  heap size= 33554432
 0(8360)  used= 8, used+overhead=17584, free=33536848
 0(8360)  max used (+overhead)= 1631040
 0(8360) dumping free list:
 0(8360) hash =   1 fragments no.:    44, unused:     0
         bucket size:         8 -         8 (first         8)
 0(8360) hash =   2 fragments no.:    10, unused:     0
         bucket size:        16 -        16 (first        16)
 0(8360) hash =   3 fragments no.:     3, unused:     0
         bucket size:        24 -        24 (first        24)
 0(8360) hash =   4 fragments no.:    37, unused:     0
         bucket size:        32 -        32 (first        32)
 0(8360) hash =   5 fragments no.:     5, unused:     0
         bucket size:        40 -        40 (first        40)
 0(8360) hash =   6 fragments no.:     5, unused:     0
         bucket size:        48 -        48 (first        48)
 0(8360) hash =   8 fragments no.:     2, unused:     0
         bucket size:        64 -        64 (first        64)
 0(8360) hash =  11 fragments no.:     2, unused:     0
         bucket size:        88 -        88 (first        88)
 0(8360) hash =  13 fragments no.:     1, unused:     0
         bucket size:       104 -       104 (first       104)
 0(8360) hash =  16 fragments no.:     1, unused:     0
         bucket size:       128 -       128 (first       128)
 0(8360) hash =  40 fragments no.:     1, unused:     0
         bucket size:       320 -       320 (first       320)
 0(8360) hash =  97 fragments no.:     1, unused:     0
         bucket size:       776 -       776 (first       776)
 0(8360) hash = 103 fragments no.:     1, unused:     0
         bucket size:       824 -       824 (first       824)
 0(8360) hash = 130 fragments no.:     1, unused:     0
         bucket size:      1040 -      1040 (first      1040)
 0(8360) hash = 135 fragments no.:     1, unused:     0
         bucket size:      1080 -      1080 (first      1080)
 0(8360) hash = 138 fragments no.:     1, unused:     0
         bucket size:      1104 -      1104 (first      1104)
 0(8360) hash = 350 fragments no.:     1, unused:     0
         bucket size:      2800 -      2800 (first      2800)
 0(8360) hash = 354 fragments no.:     1, unused:     0
         bucket size:      2832 -      2832 (first      2832)
 0(8360) hash = 396 fragments no.:     1, unused:     0
         bucket size:      3168 -      3168 (first      3168)
 0(8360) hash = 466 fragments no.:     1, unused:     0
         bucket size:      3728 -      3728 (first      3728)
 0(8360) hash = 512 fragments no.:     2, unused:     0
         bucket size:      4096 -      4096 (first      4096)
 0(8360) hash = 1024 fragments no.:     2, unused:     0
         bucket size:      8192 -      8192 (first      8192)
 0(8360) hash = 2055 fragments no.:     1, unused:     0
         bucket size:   1048576 -   2097152 (first   1572864)
 0(8360) hash = 2059 fragments no.:     1, unused:     0
         bucket size:  16777216 -  33554432 (first  31918992)
 0(8360) TOTAL:    126 free fragments = 33536848 free bytes
 0(8360) -----------------------------
 0(8360) shm_mem_destroy
 0(8360) destroying the shared memory lock
 0(8360) terminating due to SIGCHLD

Ethereal Dump:

  0.000000 169.198.11.19 -> 169.198.11.110 SIP Request: REGISTER sip: 169.198.11.110
  0.003919 169.198.11.19 -> 169.198.11.110 SIP Request: SUBSCRIBE sip:test@xxxxxxxxxxxxxx
  0.005254 169.198.11.110 -> 169.198.11.19 SIP Status: 404 Not Found
  0.009548 169.198.11.110 -> 169.198.11.19 SIP Status: 200 OK    (1 bindings)
  5.764521 169.198.11.175 -> 169.198.11.110 SIP Request: REGISTER sip: 169.198.11.110
  5.765817 169.198.11.110 -> 169.198.11.175 SIP Status: 200 OK    (1 bindings)
  5.812108 169.198.11.175 -> 169.198.11.110 SIP Request: SUBSCRIBE sip:test_store@xxxxxxxxxxxxxx
  5.813533 169.198.11.110 -> 169.198.11.175 SIP Request: SUBSCRIBE sip:test_store@xxxxxxxxxxxxxx:5066;transport=udp
  5.816955 169.198.11.175 -> 169.198.11.110 SIP Status: 405 Method Not Allowed
  5.817543 169.198.11.110 -> 169.198.11.175 SIP Status: 405 Method Not Allowed
 10.436726 169.198.11.175 -> 169.198.11.110 SIP/SDP Request: INVITE sip:test@xxxxxxxxxxxxxx, with session description
 10.438792 169.198.11.110 -> 169.198.11.175 SIP Status: 100 trying -- your call is important to us
 10.439167 169.198.11.110 -> 169.198.11.19 SIP/SDP Request: INVITE sip:test@xxxxxxxxxxxxx:5069;transport=udp, with session description
 10.440928 169.198.11.19 -> 169.198.11.110 SIP Status: 100 Trying
 10.463953 169.198.11.19 -> 169.198.11.110 SIP Status: 100 Trying
 10.482847 169.198.11.19 -> 169.198.11.110 SIP Status: 502 Bad Gateway
 10.483365 169.198.11.110 -> 169.198.11.19 SIP Request: ACK sip:test@xxxxxxxxxxxxx:5069;transport=udp
 10.483506 169.198.11.110 -> 169.198.11.175 SIP Status: 502 Bad Gateway
 10.489106 169.198.11.175 -> 169.198.11.110 SIP Request: ACK sip:test@xxxxxxxxxxxxxx
 11.992469 169.198.11.19 -> 169.198.11.110 SIP/SDP Status: 200 OK, with session description
 11.993609 169.198.11.110 -> 169.198.11.175 SIP/SDP Status: 200 OK, with session description

rtpproxy dump:

received command "U 76ab342a-88ec-db11-89dd-00187185e000@xxxxxxxxxxx 169.198.11.175 5020 66b6342a-88ec-db11-89dd-00187185e000;1"
new session 76ab342a-88ec-db11-89dd-00187185e000@xxxxxxxxxxx, tag 66b6342a-88ec-db11-89dd-00187185e000;1 requested, type strong
new session on a port 35000 created, tag 66b6342a-88ec-db11-89dd-00187185e000;1
pre-filling caller's address with 169.198.11.175:5020
sending reply "35000 169.198.11.110
"
received command "U 76ab342a-88ec-db11-89dd-00187185e000@xxxxxxxxxxx 169.198.11.175 5022 66b6342a-88ec-db11-89dd-00187185e000;2"
new session 76ab342a-88ec-db11-89dd-00187185e000@xxxxxxxxxxx, tag 66b6342a-88ec-db11-89dd-00187185e000;2 requested, type strong
new session on a port 35002 created, tag 66b6342a-88ec-db11-89dd-00187185e000;2
pre-filling caller's address with 169.198.11.175:5022
sending reply "35002 169.198.11.110
"
received command "L 76ab342a-88ec-db11-89dd-00187185e000@xxxxxxxxxxx 169.198.11.19 5002 66b6342a-88ec-db11-89dd-00187185e000;1 609d6b2c-46ec-db11-980d-001372710463;1"
lookup on a ports 35000/35004, session timer restarted
pre-filling callee's address with 169.198.11.19:5002
sending reply "35004 169.198.11.110

Thanks in advance
-------------------------------------------------------------------------
This SF.net email is sponsored by DB2 Express
Download DB2 Express C - the FREE version of DB2 express and take
control of your XML. No limits. Just data. Click to get it now.
http://sourceforge.net/powerbar/db2/_______________________________________________________

Posting: mailto:Openh323gk-users@xxxxxxxxxxxxxxxxxxxxx
Archive: http://sourceforge.net/mailarchive/forum.php?forum_id=8549
Unsubscribe: http://lists.sourceforge.net/lists/listinfo/openh323gk-users
Homepage: http://www.gnugk.org/
-------------------------------------------------------------------------
This SF.net email is sponsored by DB2 Express
Download DB2 Express C - the FREE version of DB2 express and take
control of your XML. No limits. Just data. Click to get it now.
http://sourceforge.net/powerbar/db2/
_______________________________________________________

Posting: mailto:Openh323gk-users@xxxxxxxxxxxxxxxxxxxxx
Archive: http://sourceforge.net/mailarchive/forum.php?forum_id=8549
Unsubscribe: http://lists.sourceforge.net/lists/listinfo/openh323gk-users
Homepage: http://www.gnugk.org/

[Index of Archives]     [SIP]     [Open H.323]     [Gnu Gatekeeper]     [Asterisk PBX]     [ISDN Cause Codes]     [Yosemite News]

  Powered by Linux