Script started on Tue 30 Mar 2004 04:56:58 PM CST
# /usr/local/sbin/ser
 0(29441) loading module /usr/local/lib/ser/modules/mysql.so
 0(29441) loading module /usr/local/lib/ser/modules/sl.so
 0(29441) loading module /usr/local/lib/ser/modules/tm.so
 0(29441) loading module /usr/local/lib/ser/modules/rr.so
 0(29441) loading module /usr/local/lib/ser/modules/maxfwd.so
 0(29441) loading module /usr/local/lib/ser/modules/usrloc.so
 0(29441) loading module /usr/local/lib/ser/modules/registrar.so
 0(29441) set_mod_param_regex: usrloc matches module usrloc
 0(29441) set_mod_param_regex: found <db_mode> in module usrloc [/usr/local/lib/ser/modules/usrloc.so]
 0(29441) set_mod_param_regex: rr matches module rr
 0(29441) set_mod_param_regex: found <enable_full_lr> in module rr [/usr/local/lib/ser/modules/rr.so]
 0(29441) find_export: found <mf_process_maxfwd_header> in module maxfwd_module [/usr/local/lib/ser/modules/maxfwd.so]
 0(29441) find_export: found <sl_send_reply> in module sl_module [/usr/local/lib/ser/modules/sl.so]
 0(29441) find_export: found <sl_send_reply> in module sl_module [/usr/local/lib/ser/modules/sl.so]
 0(29441) find_export: found <record_route> in module rr [/usr/local/lib/ser/modules/rr.so]
 0(29441) find_export: found <sl_send_reply> in module sl_module [/usr/local/lib/ser/modules/sl.so]
 0(29441) find_export: found <t_relay> in module tm [/usr/local/lib/ser/modules/tm.so]
 0(29441) find_export: found <sl_reply_error> in module sl_module [/usr/local/lib/ser/modules/sl.so]
 0(29441) routing table 0:
 0(29441) if ( 0(29441) NOT(  0(29441)  external_module_call( 0(29441) f_ptr<fcf20ca0> 0(29441) , "10" 0(29441) );  0(29441)  external_module_call( 0(29441) f_ptr<fcf20ca0> 0(29441) , "10" 0(29441) );  0(29441)  ) 0(29441) ) { 0(29441)  external_module_call( 0(29441) f_ptr<ff1518c0> 0(29441) , "483" 0(29441) , "Too Many Hops" 0(29441) );  0(29441) drop( 0(29441) type<0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) UNKNOWN 0(29441) <UNKNOWN> 0(29441) 65535 0(29441) ) { 0(29441)  external_module_call( 0(29441) f_ptr<ff1518c0> 0(29441) , "513" 0(29441) , "Message too big" 0(29441) );  0(29441) drop( 0(29441) type<0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441)  external_module_call( 0(29441) f_ptr<fcf435e0> 0(29441) );  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "REGISTER" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED REGISTER ******************************
" 0(29441) );  0(29441)  external_module_call( 0(29441) f_ptr<ff1518c0> 0(29441) , "200" 0(29441) , "ok" 0(29441) );  0(29441) drop( 0(29441) type<0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "OPTIONS" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "*********************  RECEIVED OPTIONS MESSAGE ****************************
" 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "INFO" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "*********************  RECEIVED INFO MESSAGE ****************************
" 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "CANCEL" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "*********************  RECEIVED CANCEL MESSAGE ****************************
" 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "ACK" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED ACK ***********************************
" 0(29441) );  0(29441) drop( 0(29441) type<0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "INVITE" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED INVITE ********************************
" 0(29441) );  0(29441) sethostport( 0(29441) "10.31.15.253:4000" 0(29441) );  0(29441) if ( 0(29441) NOT(  0(29441)  external_module_call( 0(29441) f_ptr<fcf79e00> 0(29441) );  0(29441)  external_module_call( 0(29441) f_ptr<fcf79e00> 0(29441) );  0(29441)  ) 0(29441) ) { 0(29441)  external_module_call( 0(29441) f_ptr<ff1518e0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) UNKNOWN 0(29441) <UNKNOWN> 0(29441) 65535 0(29441) ) { 0(29441)  external_module_call( 0(29441) f_ptr<ff1518c0> 0(29441) , "513" 0(29441) , "Message too big" 0(29441) );  0(29441) drop( 0(29441) type<0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441)  external_module_call( 0(29441) f_ptr<fcf435e0> 0(29441) );  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "REGISTER" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED REGISTER ******************************
" 0(29441) );  0(29441)  external_module_call( 0(29441) f_ptr<ff1518c0> 0(29441) , "200" 0(29441) , "ok" 0(29441) );  0(29441) drop( 0(29441) type<0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "OPTIONS" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "*********************  RECEIVED OPTIONS MESSAGE ****************************
" 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "INFO" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "*********************  RECEIVED INFO MESSAGE ****************************
" 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "CANCEL" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "*********************  RECEIVED CANCEL MESSAGE ****************************
" 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "ACK" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED ACK ***********************************
" 0(29441) );  0(29441) drop( 0(29441) type<0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "INVITE" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED INVITE ********************************
" 0(29441) );  0(29441) sethostport( 0(29441) "10.31.15.253:4000" 0(29441) );  0(29441) if ( 0(29441) NOT(  0(29441)  external_module_call( 0(29441) f_ptr<fcf79e00> 0(29441) );  0(29441)  external_module_call( 0(29441) f_ptr<fcf79e00> 0(29441) );  0(29441)  ) 0(29441) ) { 0(29441)  external_module_call( 0(29441) f_ptr<ff1518e0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) } else { 0(29441) };  0(29441)  external_module_call( 0(29441) f_ptr<fcf435e0> 0(29441) );  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "REGISTER" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED REGISTER ******************************
" 0(29441) );  0(29441)  external_module_call( 0(29441) f_ptr<ff1518c0> 0(29441) , "200" 0(29441) , "ok" 0(29441) );  0(29441) drop( 0(29441) type<0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "OPTIONS" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "*********************  RECEIVED OPTIONS MESSAGE ****************************
" 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "INFO" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "*********************  RECEIVED INFO MESSAGE ****************************
" 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "CANCEL" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "*********************  RECEIVED CANCEL MESSAGE ****************************
" 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "ACK" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED ACK ***********************************
" 0(29441) );  0(29441) drop( 0(29441) type<0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "INVITE" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED INVITE ********************************
" 0(29441) );  0(29441) sethostport( 0(29441) "10.31.15.253:4000" 0(29441) );  0(29441) if ( 0(29441) NOT(  0(29441)  external_module_call( 0(29441) f_ptr<fcf79e00> 0(29441) );  0(29441)  external_module_call( 0(29441) f_ptr<fcf79e00> 0(29441) );  0(29441)  ) 0(29441) ) { 0(29441)  external_module_call( 0(29441) f_ptr<ff1518e0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "REGISTER" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED REGISTER ******************************
" 0(29441) );  0(29441)  external_module_call( 0(29441) f_ptr<ff1518c0> 0(29441) , "200" 0(29441) , "ok" 0(29441) );  0(29441) drop( 0(29441) type<0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "OPTIONS" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "*********************  RECEIVED OPTIONS MESSAGE ****************************
" 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "INFO" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "*********************  RECEIVED INFO MESSAGE ****************************
" 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "CANCEL" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "*********************  RECEIVED CANCEL MESSAGE ****************************
" 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "ACK" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED ACK ***********************************
" 0(29441) );  0(29441) drop( 0(29441) type<0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "INVITE" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED INVITE ********************************
" 0(29441) );  0(29441) sethostport( 0(29441) "10.31.15.253:4000" 0(29441) );  0(29441) if ( 0(29441) NOT(  0(29441)  external_module_call( 0(29441) f_ptr<fcf79e00> 0(29441) );  0(29441)  external_module_call( 0(29441) f_ptr<fcf79e00> 0(29441) );  0(29441)  ) 0(29441) ) { 0(29441)  external_module_call( 0(29441) f_ptr<ff1518e0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "OPTIONS" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "*********************  RECEIVED OPTIONS MESSAGE ****************************
" 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "INFO" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "*********************  RECEIVED INFO MESSAGE ****************************
" 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "CANCEL" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "*********************  RECEIVED CANCEL MESSAGE ****************************
" 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "ACK" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED ACK ***********************************
" 0(29441) );  0(29441) drop( 0(29441) type<0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "INVITE" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED INVITE ********************************
" 0(29441) );  0(29441) sethostport( 0(29441) "10.31.15.253:4000" 0(29441) );  0(29441) if ( 0(29441) NOT(  0(29441)  external_module_call( 0(29441) f_ptr<fcf79e00> 0(29441) );  0(29441)  external_module_call( 0(29441) f_ptr<fcf79e00> 0(29441) );  0(29441)  ) 0(29441) ) { 0(29441)  external_module_call( 0(29441) f_ptr<ff1518e0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "INFO" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "*********************  RECEIVED INFO MESSAGE ****************************
" 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "CANCEL" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "*********************  RECEIVED CANCEL MESSAGE ****************************
" 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "ACK" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED ACK ***********************************
" 0(29441) );  0(29441) drop( 0(29441) type<0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "INVITE" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED INVITE ********************************
" 0(29441) );  0(29441) sethostport( 0(29441) "10.31.15.253:4000" 0(29441) );  0(29441) if ( 0(29441) NOT(  0(29441)  external_module_call( 0(29441) f_ptr<fcf79e00> 0(29441) );  0(29441)  external_module_call( 0(29441) f_ptr<fcf79e00> 0(29441) );  0(29441)  ) 0(29441) ) { 0(29441)  external_module_call( 0(29441) f_ptr<ff1518e0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "CANCEL" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "*********************  RECEIVED CANCEL MESSAGE ****************************
" 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "ACK" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED ACK ***********************************
" 0(29441) );  0(29441) drop( 0(29441) type<0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "INVITE" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED INVITE ********************************
" 0(29441) );  0(29441) sethostport( 0(29441) "10.31.15.253:4000" 0(29441) );  0(29441) if ( 0(29441) NOT(  0(29441)  external_module_call( 0(29441) f_ptr<fcf79e00> 0(29441) );  0(29441)  external_module_call( 0(29441) f_ptr<fcf79e00> 0(29441) );  0(29441)  ) 0(29441) ) { 0(29441)  external_module_call( 0(29441) f_ptr<ff1518e0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "ACK" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED ACK ***********************************
" 0(29441) );  0(29441) drop( 0(29441) type<0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "INVITE" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED INVITE ********************************
" 0(29441) );  0(29441) sethostport( 0(29441) "10.31.15.253:4000" 0(29441) );  0(29441) if ( 0(29441) NOT(  0(29441)  external_module_call( 0(29441) f_ptr<fcf79e00> 0(29441) );  0(29441)  external_module_call( 0(29441) f_ptr<fcf79e00> 0(29441) );  0(29441)  ) 0(29441) ) { 0(29441)  external_module_call( 0(29441) f_ptr<ff1518e0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) } else { 0(29441) };  0(29441) if ( 0(29441) method 0(29441) == 0(29441) "INVITE" 0(29441) ) { 0(29441) log( 0(29441) 1 0(29441) , "**************************  RECEIVED INVITE ********************************
" 0(29441) );  0(29441) sethostport( 0(29441) "10.31.15.253:4000" 0(29441) );  0(29441) if ( 0(29441) NOT(  0(29441)  external_module_call( 0(29441) f_ptr<fcf79e00> 0(29441) );  0(29441)  external_module_call( 0(29441) f_ptr<fcf79e00> 0(29441) );  0(29441)  ) 0(29441) ) { 0(29441)  external_module_call( 0(29441) f_ptr<ff1518e0> 0(29441) );  0(29441) } else { 0(29441) };  0(29441) } else { 0(29441) };  0(29441) 
Listening on 
              10.31.14.200 [10.31.14.200]:5060
Aliases: loghost:5060 caveman:5060 
WARNING: no fork mode 
 0(29441) DEBUG: init_mod: mysql
 0(29441) mysql - initializing
 0(29441) DEBUG: init_mod: sl_module
stateless - initializing
 0(29441) DEBUG: register_fifo_cmd: new command (sl_stats) registered
 0(29441) DEBUG: MD5 calculated: 9c818f52bcc4fffa9610568f4be52539
 0(29441) DEBUG: init_mod: tm
 0(29441) TM - initializing...
 0(29441) Call-ID initialization: '58282eed'
 0(29441) DEBUG: register_fifo_cmd: new command (t_uac_dlg) registered
 0(29441) DEBUG: register_fifo_cmd: new command (t_hash) registered
 0(29441) DEBUG: lock_initialize: lock initialization started
 0(29441) DEBUG: register_fifo_cmd: new command (t_stats) registered
 0(29441) Warning: uac does not spread accross the whole hash table
 0(29441) DEBUG: MD5 calculated: 6846af86154c482b36472261b1d13258
 0(29441) DEBUG: MD5 calculated: 19d4d767dedba5e9d0a57f60eb631aa7
 0(29441) DEBUG: init_mod: rr
 0(29441) rr - initializing
 0(29441) DEBUG: init_mod: maxfwd_module
Maxfwd module- initializing
 0(29441) DEBUG: init_mod: usrloc
 0(29441) usrloc - initializing
 0(29441) DEBUG: register_fifo_cmd: new command (ul_stats) registered
 0(29441) DEBUG: register_fifo_cmd: new command (ul_rm) registered
 0(29441) DEBUG: register_fifo_cmd: new command (ul_rm_contact) registered
 0(29441) DEBUG: register_fifo_cmd: new command (ul_dump) registered
 0(29441) DEBUG: register_fifo_cmd: new command (ul_flush) registered
 0(29441) DEBUG: register_fifo_cmd: new command (ul_add) registered
 0(29441) DEBUG: register_fifo_cmd: new command (ul_show_contact) registered
 0(29441) find_export: found <db_use_table> in module mysql [/usr/local/lib/ser/modules/mysql.so]
 0(29441) find_export: found <db_init> in module mysql [/usr/local/lib/ser/modules/mysql.so]
 0(29441) find_export: found <db_close> in module mysql [/usr/local/lib/ser/modules/mysql.so]
 0(29441) find_export: found <db_query> in module mysql [/usr/local/lib/ser/modules/mysql.so]
 0(29441) find_export: found <db_raw_query> in module mysql [/usr/local/lib/ser/modules/mysql.so]
 0(29441) find_export: found <db_free_query> in module mysql [/usr/local/lib/ser/modules/mysql.so]
 0(29441) find_export: found <db_insert> in module mysql [/usr/local/lib/ser/modules/mysql.so]
 0(29441) find_export: found <db_delete> in module mysql [/usr/local/lib/ser/modules/mysql.so]
 0(29441) find_export: found <db_update> in module mysql [/usr/local/lib/ser/modules/mysql.so]
 0(29441) mod_init(): Database connection opened successfuly
 0(29441) DEBUG: init_mod: registrar
 0(29441) registrar - initializing
 0(29441) find_export: found <sl_send_reply> in module sl_module [/usr/local/lib/ser/modules/sl.so]
 0(29441) find_export: found <ul_bind_usrloc> in module usrloc [/usr/local/lib/ser/modules/usrloc.so]
 0(29441) find_export: found <ul_register_udomain> in module usrloc [/usr/local/lib/ser/modules/usrloc.so]
 0(29441) find_export: found <ul_get_all_ucontacts> in module usrloc [/usr/local/lib/ser/modules/usrloc.so]
 0(29441) find_export: found <ul_insert_urecord> in module usrloc [/usr/local/lib/ser/modules/usrloc.so]
 0(29441) find_export: found <ul_delete_urecord> in module usrloc [/usr/local/lib/ser/modules/usrloc.so]
 0(29441) find_export: found <ul_get_urecord> in module usrloc [/usr/local/lib/ser/modules/usrloc.so]
 0(29441) find_export: found <ul_lock_udomain> in module usrloc [/usr/local/lib/ser/modules/usrloc.so]
 0(29441) find_export: found <ul_unlock_udomain> in module usrloc [/usr/local/lib/ser/modules/usrloc.so]
 0(29441) find_export: found <ul_release_urecord> in module usrloc [/usr/local/lib/ser/modules/usrloc.so]
 0(29441) find_export: found <ul_insert_ucontact> in module usrloc [/usr/local/lib/ser/modules/usrloc.so]
 0(29441) find_export: found <ul_delete_ucontact> in module usrloc [/usr/local/lib/ser/modules/usrloc.so]
 0(29441) find_export: found <ul_get_ucontact> in module usrloc [/usr/local/lib/ser/modules/usrloc.so]
 0(29441) find_export: found <ul_update_ucontact> in module usrloc [/usr/local/lib/ser/modules/usrloc.so]
 0(0) fixing /usr/local/lib/ser/modules/maxfwd.so mf_process_maxfwd_header
 0(0) fixing /usr/local/lib/ser/modules/sl.so sl_send_reply
 0(0) fixing /usr/local/lib/ser/modules/sl.so sl_send_reply
 0(0) fixing /usr/local/lib/ser/modules/rr.so record_route
 0(0) fixing /usr/local/lib/ser/modules/sl.so sl_send_reply
 0(0) fixing /usr/local/lib/ser/modules/tm.so t_relay
 0(0) fixing /usr/local/lib/ser/modules/sl.so sl_reply_error
 0(0) INFO: udp_init: SO_RCVBUF is initially 8192
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 16384
 0(0) DEBUG: setting SO_RCVBUF; set=16384,verify=16384
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 32768
 0(0) DEBUG: setting SO_RCVBUF; set=32768,verify=32768
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 65536
 0(0) DEBUG: setting SO_RCVBUF; set=65536,verify=65536
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 131072
 0(0) DEBUG: setting SO_RCVBUF; set=131072,verify=131072
 0(0) DEBUG: udp_init: trying SO_RCVBUF: 262144
 0(0) DEBUG: setting SO_RCVBUF; set=262144,verify=262144
 0(0) INFO: udp_init: SO_RCVBUF is finally 262144
 1(0) DEBUG: init_mod_child (-1): tm
 1(0) DEBUG: callid: '58282eed-0@10.31.14.200'
 1(0) DEBUG: init_mod_child (-1): usrloc
 1(29442) DBG: open_uac_fifo: opening fifo...
 1(29442) DEBUG: open_fifo_server: FIFO stat failed: Error 0
 1(29442) DEBUG: FIFO created @ /tmp/ser_fifo
 1(29442) DEBUG: fifo /tmp/ser_fifo opened, mode=432
 2(0) INFO: fifo process starting: 29443
 2(0) DEBUG: init_mod_child (-2): tm
 2(0) DEBUG: callid: '58282eed-0@10.31.14.200'
 2(0) DEBUG: init_mod_child (-2): usrloc
 2(29443) SER: open_uac_fifo: fifo server up at /tmp/ser_fifo...
 0(29441) DEBUG: init_mod_child (1): tm
 0(29441) DEBUG: callid: '58282eed-29441@10.31.14.200'
 0(29441) DEBUG: init_mod_child (1): usrloc
 0(29441) SIP Request:
 0(29441)  method:  <INVITE>
 0(29441)  uri:     <sip:5551111234@10.31.14.200;dtg=LAB_LA_TERM>
 0(29441)  version: <SIP/2.0>
 0(29441) parse_headers: flags=1
 0(29441) end of header reached, state=5
 0(29441) parse_headers: Via found, flags=1
 0(29441) parse_headers: this is the first via
 0(29441) After parse_msg...
 0(29441) preparing to run routing scripts...
 0(29441) DEBUG : is_maxfwd_present: searching for max_forwards header
 0(29441) parse_headers: flags=128
 0(29441) end of header reached, state=9
 0(29441) DEBUG: get_hdr_field: <To> [36]; uri=[sip:5551111234@10.31.14.200:5060] 
 0(29441) DEBUG: to body [<sip:5551111234@10.31.14.200:5060>
]
 0(29441) get_hdr_field: cseq <CSeq>: <3267> <INVITE>
 0(29441) DEBUG: get_hdr_body : content_length=152
 0(29441) found end of header
 0(29441) DEBUG: is_maxfwd_present: max_forwards header not found!
 0(29441) DEBUG: add_param: pstn-params=808182808882
 0(29441) DEBUG: add_param: tag=72
 0(29441) end of header reached, state=29
 0(29441) **************************  RECEIVED INVITE ********************************
 0(29441) DEBUG: t_addifnew: msg id=1 , global msg id=0 , T on entrance=ffffffff
 0(29441) parse_headers: flags=-1
 0(29441) parse_headers: flags=60
 0(29441) t_lookup_request: start searching: hash=35190, isACK=0
 0(29441) DEBUG: proceeding to pre-RFC3261 transaction matching
 0(29441) DEBUG: t_lookup_request: no transaction found
 0(29441) SER: new INVITE
 0(29441) parse_headers: flags=-1
 0(29441) check_via_address(10.31.14.253, 10.31.14.253, 0)
 0(29441) WARNING:vqm_resize: resize(0) called
 0(29441) DEBUG: reply sent out. buf=9c390: SIP/2.0 1..., shmem=fd184a28: SIP/2.0 1
 0(29441) DEBUG: t_reply: finished
 0(29441) DEBUG: mk_proxy: doing DNS lookup...
 0(29441) check_via_address(10.31.14.253, 10.31.14.253, 0)
 0(29441) DEBUG: add_to_tail_of_timer[4]: fd18332c
 0(29441) DEBUG: add_to_tail_of_timer[0]: fd183340
 0(29441) SER: new transaction fwd'ed
 0(29441) receive_msg: cleaning up
 0(29441) SIP Reply  (status):
 0(29441)  version: <SIP/2.0>
 0(29441)  status:  <100>
 0(29441)  reason:  <Trying>
 0(29441) parse_headers: flags=1
 0(29441) Found param type 232, <branch> = <z9hG4bK6798.3d17.0>; state=16
 0(29441) end of header reached, state=5
 0(29441) parse_headers: Via found, flags=1
 0(29441) parse_headers: this is the first via
 0(29441) After parse_msg...
 0(29441) check_self - checking if host==us: 12==12 &&  [10.31.14.200] == [10.31.14.200]
 0(29441) check_self - checking if port 5060 matches port 5060
 0(29441) forward_reply: found module tm, passing reply to it
 0(29441) DEBUG: t_check: msg id=2 global id=1 T start=ffffffff
 0(29441) parse_headers: flags=17
 0(29441) end of header reached, state=5
 0(29441) parse_headers: Via found, flags=17
 0(29441) parse_headers: this is the second via
 0(29441) DEBUG: add_param: tag=61
 0(29441) end of header reached, state=29
 0(29441) DEBUG: get_hdr_field: <To> [43]; uri=[sip:5551111234@10.31.14.200:5060] 
 0(29441) DEBUG: to body [<sip:5551111234@10.31.14.200:5060>]
 0(29441) get_hdr_field: cseq <CSeq>: <3267> <INVITE>
 0(29441) parse_headers: flags=4
 0(29441) DEBUG: t_reply_matching: hash 35190 label 29139 branch 0
 0(29441) DEBUG: t_reply_matching: reply matched (T=fd183200)!
 0(29441) DEBUG: t_check: msg id=2 global id=2 T end=fd183200
 0(29441) DEBUG: t_on_reply: org. status uas=100, uac[0]=0 local=0 is_invite=1)
 0(29441) ->>>>>>>>> T_code=100, new_code=100
 0(29441) DEBUG: relay_reply: branch=0, save=0, relay=-1
 0(29441) DEBUG: add_to_tail_of_timer[1]: fd183340
 0(29441) receive_msg: cleaning up
 0(29441) SIP Reply  (status):
 0(29441)  version: <SIP/2.0>
 0(29441)  status:  <503>
 0(29441)  reason:  <Service Unavailable>
 0(29441) parse_headers: flags=1
 0(29441) Found param type 232, <branch> = <z9hG4bK6798.3d17.0>; state=16
 0(29441) end of header reached, state=5
 0(29441) parse_headers: Via found, flags=1
 0(29441) parse_headers: this is the first via
 0(29441) After parse_msg...
 0(29441) check_self - checking if host==us: 12==12 &&  [10.31.14.200] == [10.31.14.200]
 0(29441) check_self - checking if port 5060 matches port 5060
 0(29441) forward_reply: found module tm, passing reply to it
 0(29441) DEBUG: t_check: msg id=3 global id=2 T start=ffffffff
 0(29441) parse_headers: flags=17
 0(29441) end of header reached, state=5
 0(29441) parse_headers: Via found, flags=17
 0(29441) parse_headers: this is the second via
 0(29441) DEBUG: add_param: tag=61
 0(29441) end of header reached, state=29
 0(29441) DEBUG: get_hdr_field: <To> [43]; uri=[sip:5551111234@10.31.14.200:5060] 
 0(29441) DEBUG: to body [<sip:5551111234@10.31.14.200:5060>]
 0(29441) get_hdr_field: cseq <CSeq>: <3267> <INVITE>
 0(29441) parse_headers: flags=4
 0(29441) DEBUG: t_reply_matching: hash 35190 label 29139 branch 0
 0(29441) DEBUG: t_reply_matching: reply matched (T=fd183200)!
 0(29441) DEBUG: t_check: msg id=3 global id=3 T end=fd183200
 0(29441) DEBUG: t_on_reply: org. status uas=100, uac[0]=100 local=0 is_invite=1)
 0(29441) parse_headers: flags=4
 0(29441) ->>>>>>>>> T_code=100, new_code=503
 0(29441) DEBUG: relay_reply: branch=0, save=0, relay=0
 0(29441)  old size: 385, new size: 328
 0(29441) build_res_from_sip_res: copied size: orig:90, new: 33, rest: 295 msg=
SIP/2.0 503 Service Unavailable
Via: SIP/2.0/UDP 10.31.14.253:4000
From: <sip:5127351243@10.31.14.253:4000>;pstn-params=808182808882;tag=72
To: <sip:5551111234@10.31.14.200:5060>;tag=61
Call-ID: 947552_97051161@10.31.14.253
CSeq: 3267 INVITE
Record-Route: <sip:5551111234@10.31.14.200;ftag=72;lr=on>
Content-Length: 0


 0(29441) DEBUG: reply relayed. buf=9c5d0: SIP/2.0 5..., shmem=fd1850e0: SIP/2.0 5
 0(29441) DEBUG: cleanup_uacs: RETR/FR timers reset
 0(29441) DEBUG: add_to_tail_of_timer[4]: fd1832b4
 0(29441) DEBUG: add_to_tail_of_timer[0]: fd1832c8
 0(29441) receive_msg: cleaning up
 0(29441) SIP Request:
 0(29441)  method:  <ACK>
 0(29441)  uri:     <sip:5551111234@10.31.14.200>
 0(29441)  version: <SIP/2.0>
 0(29441) parse_headers: flags=1
 0(29441) end of header reached, state=5
 0(29441) parse_headers: Via found, flags=1
 0(29441) parse_headers: this is the first via
 0(29441) After parse_msg...
 0(29441) DEBUG : sl_filter_ACK: to late to be a local ACK!
 0(29441) preparing to run routing scripts...
 0(29441) DEBUG : is_maxfwd_present: searching for max_forwards header
 0(29441) parse_headers: flags=128
 0(29441) DEBUG: add_param: tag=61
 0(29441) end of header reached, state=29
 0(29441) DEBUG: get_hdr_field: <To> [43]; uri=[sip:5551111234@10.31.14.200:5060] 
 0(29441) DEBUG: to body [<sip:5551111234@10.31.14.200:5060>]
 0(29441) get_hdr_field: cseq <CSeq>: <3267> <ACK>
 0(29441) DEBUG: get_hdr_body : content_length=0
 0(29441) found end of header
 0(29441) DEBUG: is_maxfwd_present: max_forwards header not found!
 0(29441) DEBUG: add_param: pstn-params=808182808882
 0(29441) DEBUG: add_param: tag=72
 0(29441) end of header reached, state=29
 0(29441) **************************  RECEIVED ACK ***********************************
 0(29441) receive_msg: cleaning up
 1(29442) DEBUG: timer routine:1,tl=fd183340 next=0
 1(29442) DEBUG: timer routine:4,tl=fd18332c next=fd1832b4
 1(29442) DEBUG: timer routine:4,tl=fd1832b4 next=0
 1(29442) DEBUG: retransmission_handler : reply resending (t=fd183200, SIP/2.0 5 ... )
 1(29442) DEBUG: reply retransmitted. buf=fcf957a8: SIP/2.0 5..., shmem=fd1850e0: SIP/2.0 5
 1(29442) DEBUG: add_to_tail_of_timer[5]: fd1832b4
 1(29442) DEBUG: retransmission_handler : done
 0(29441) SIP Request:
 0(29441)  method:  <INVITE>
 0(29441)  uri:     <sip:5551111235@10.31.14.200;dtg=LAB_LA_TERM>
 0(29441)  version: <SIP/2.0>
 0(29441) parse_headers: flags=1
 0(29441) end of header reached, state=5
 0(29441) parse_headers: Via found, flags=1
 0(29441) parse_headers: this is the first via
 0(29441) After parse_msg...
 0(29441) preparing to run routing scripts...
 0(29441) DEBUG : is_maxfwd_present: searching for max_forwards header
 0(29441) parse_headers: flags=128
 0(29441) end of header reached, state=9
 0(29441) DEBUG: get_hdr_field: <To> [36]; uri=[sip:5551111235@10.31.14.200:5060] 
 0(29441) DEBUG: to body [<sip:5551111235@10.31.14.200:5060>
]
 0(29441) get_hdr_field: cseq <CSeq>: <5023> <INVITE>
 0(29441) DEBUG: get_hdr_body : content_length=152
 0(29441) found end of header
 0(29441) DEBUG: is_maxfwd_present: max_forwards header not found!
 0(29441) DEBUG: add_param: pstn-params=808182808882
 0(29441) DEBUG: add_param: tag=72
 0(29441) end of header reached, state=29
 0(29441) **************************  RECEIVED INVITE ********************************
 0(29441) DEBUG: t_addifnew: msg id=5 , global msg id=3 , T on entrance=ffffffff
 0(29441) parse_headers: flags=-1
 0(29441) parse_headers: flags=60
 0(29441) t_lookup_request: start searching: hash=48741, isACK=0
 0(29441) DEBUG: proceeding to pre-RFC3261 transaction matching
 0(29441) DEBUG: t_lookup_request: no transaction found
 0(29441) SER: new INVITE
 0(29441) parse_headers: flags=-1
 0(29441) check_via_address(10.31.14.253, 10.31.14.253, 0)
 0(29441) WARNING:vqm_resize: resize(0) called
 0(29441) DEBUG: reply sent out. buf=9c728: SIP/2.0 1..., shmem=fd184a28: SIP/2.0 1
 0(29441) DEBUG: t_reply: finished
 0(29441) DEBUG: mk_proxy: doing DNS lookup...
 0(29441) check_via_address(10.31.14.253, 10.31.14.253, 0)
 0(29441) DEBUG: add_to_tail_of_timer[4]: fd18538c
 0(29441) DEBUG: add_to_tail_of_timer[0]: fd1853a0
 0(29441) SER: new transaction fwd'ed
 0(29441) receive_msg: cleaning up
 0(29441) SIP Reply  (status):
 0(29441)  version: <SIP/2.0>
 0(29441)  status:  <100>
 0(29441)  reason:  <Trying>
 0(29441) parse_headers: flags=1
 0(29441) Found param type 232, <branch> = <z9hG4bK56eb.77a1.0>; state=16
 0(29441) end of header reached, state=5
 0(29441) parse_headers: Via found, flags=1
 0(29441) parse_headers: this is the first via
 0(29441) After parse_msg...
 0(29441) check_self - checking if host==us: 12==12 &&  [10.31.14.200] == [10.31.14.200]
 0(29441) check_self - checking if port 5060 matches port 5060
 0(29441) forward_reply: found module tm, passing reply to it
 0(29441) DEBUG: t_check: msg id=6 global id=5 T start=ffffffff
 0(29441) parse_headers: flags=17
 0(29441) end of header reached, state=5
 0(29441) parse_headers: Via found, flags=17
 0(29441) parse_headers: this is the second via
 0(29441) DEBUG: add_param: tag=61
 0(29441) end of header reached, state=29
 0(29441) DEBUG: get_hdr_field: <To> [43]; uri=[sip:5551111235@10.31.14.200:5060] 
 0(29441) DEBUG: to body [<sip:5551111235@10.31.14.200:5060>]
 0(29441) get_hdr_field: cseq <CSeq>: <5023> <INVITE>
 0(29441) parse_headers: flags=4
 0(29441) DEBUG: t_reply_matching: hash 48741 label 6775 branch 0
 0(29441) DEBUG: t_reply_matching: reply matched (T=fd185260)!
 0(29441) DEBUG: t_check: msg id=6 global id=6 T end=fd185260
 0(29441) DEBUG: t_on_reply: org. status uas=100, uac[0]=0 local=0 is_invite=1)
 0(29441) ->>>>>>>>> T_code=100, new_code=100
 0(29441) DEBUG: relay_reply: branch=0, save=0, relay=-1
 0(29441) DEBUG: add_to_tail_of_timer[1]: fd1853a0
 0(29441) receive_msg: cleaning up
 0(29441) SIP Reply  (status):
 0(29441)  version: <SIP/2.0>
 0(29441)  status:  <503>
 0(29441)  reason:  <Service Unavailable>
 0(29441) parse_headers: flags=1
 0(29441) Found param type 232, <branch> = <z9hG4bK56eb.77a1.0>; state=16
 0(29441) end of header reached, state=5
 0(29441) parse_headers: Via found, flags=1
 0(29441) parse_headers: this is the first via
 0(29441) After parse_msg...
 0(29441) check_self - checking if host==us: 12==12 &&  [10.31.14.200] == [10.31.14.200]
 0(29441) check_self - checking if port 5060 matches port 5060
 0(29441) forward_reply: found module tm, passing reply to it
 0(29441) DEBUG: t_check: msg id=7 global id=6 T start=ffffffff
 0(29441) parse_headers: flags=17
 0(29441) end of header reached, state=5
 0(29441) parse_headers: Via found, flags=17
 0(29441) parse_headers: this is the second via
 0(29441) DEBUG: add_param: tag=61
 0(29441) end of header reached, state=29
 0(29441) DEBUG: get_hdr_field: <To> [43]; uri=[sip:5551111235@10.31.14.200:5060] 
 0(29441) DEBUG: to body [<sip:5551111235@10.31.14.200:5060>]
 0(29441) get_hdr_field: cseq <CSeq>: <5023> <INVITE>
 0(29441) parse_headers: flags=4
 0(29441) DEBUG: t_reply_matching: hash 48741 label 6775 branch 0
 0(29441) DEBUG: t_reply_matching: reply matched (T=fd185260)!
 0(29441) DEBUG: t_check: msg id=7 global id=7 T end=fd185260
 0(29441) DEBUG: t_on_reply: org. status uas=100, uac[0]=100 local=0 is_invite=1)
 0(29441) parse_headers: flags=4
 0(29441) ->>>>>>>>> T_code=100, new_code=503
 0(29441) DEBUG: relay_reply: branch=0, save=0, relay=0
 0(29441)  old size: 385, new size: 328
 0(29441) build_res_from_sip_res: copied size: orig:90, new: 33, rest: 295 msg=
SIP/2.0 503 Service Unavailable
Via: SIP/2.0/UDP 10.31.14.253:4000
From: <sip:5127351244@10.31.14.253:4000>;pstn-params=808182808882;tag=72
To: <sip:5551111235@10.31.14.200:5060>;tag=61
Call-ID: 947553_97051261@10.31.14.253
CSeq: 5023 INVITE
Record-Route: <sip:5551111235@10.31.14.200;ftag=72;lr=on>
Content-Length: 0


 0(29441) DEBUG: reply relayed. buf=9c5d0: SIP/2.0 5..., shmem=fd186e60: SIP/2.0 5
 0(29441) DEBUG: cleanup_uacs: RETR/FR timers reset
 0(29441) DEBUG: add_to_tail_of_timer[4]: fd185314
 0(29441) DEBUG: add_to_tail_of_timer[0]: fd185328
 0(29441) receive_msg: cleaning up
 0(29441) SIP Request:
 0(29441)  method:  <ACK>
 0(29441)  uri:     <sip:5551111235@10.31.14.200>
 0(29441)  version: <SIP/2.0>
 0(29441) parse_headers: flags=1
 0(29441) end of header reached, state=5
 0(29441) parse_headers: Via found, flags=1
 0(29441) parse_headers: this is the first via
 0(29441) After parse_msg...
 0(29441) DEBUG : sl_filter_ACK: to late to be a local ACK!
 0(29441) preparing to run routing scripts...
 0(29441) DEBUG : is_maxfwd_present: searching for max_forwards header
 0(29441) parse_headers: flags=128
 0(29441) DEBUG: add_param: tag=61
 0(29441) end of header reached, state=29
 0(29441) DEBUG: get_hdr_field: <To> [43]; uri=[sip:5551111235@10.31.14.200:5060] 
 0(29441) DEBUG: to body [<sip:5551111235@10.31.14.200:5060>]
 0(29441) get_hdr_field: cseq <CSeq>: <5023> <ACK>
 0(29441) DEBUG: get_hdr_body : content_length=0
 0(29441) found end of header
 0(29441) DEBUG: is_maxfwd_present: max_forwards header not found!
 0(29441) DEBUG: add_param: pstn-params=808182808882
 0(29441) DEBUG: add_param: tag=72
 0(29441) end of header reached, state=29
 0(29441) **************************  RECEIVED ACK ***********************************
 0(29441) receive_msg: cleaning up
 1(29442) DEBUG: timer routine:1,tl=fd1853a0 next=0
 1(29442) DEBUG: timer routine:4,tl=fd18538c next=fd185314
 1(29442) DEBUG: timer routine:4,tl=fd185314 next=0
 1(29442) DEBUG: retransmission_handler : reply resending (t=fd185260, SIP/2.0 5 ... )
 1(29442) DEBUG: reply retransmitted. buf=fcf957a8: SIP/2.0 5..., shmem=fd186e60: SIP/2.0 5
 1(29442) DEBUG: add_to_tail_of_timer[5]: fd185314
 1(29442) DEBUG: retransmission_handler : done
 1(29442) DEBUG: timer routine:5,tl=fd1832b4 next=0
 1(29442) DEBUG: retransmission_handler : reply resending (t=fd183200, SIP/2.0 5 ... )
 1(29442) DEBUG: reply retransmitted. buf=fcf957a8: SIP/2.0 5..., shmem=fd1850e0: SIP/2.0 5
 1(29442) DEBUG: add_to_tail_of_timer[6]: fd1832b4
 1(29442) DEBUG: retransmission_handler : done
 1(29442) DEBUG: timer routine:5,tl=fd185314 next=0
 1(29442) DEBUG: retransmission_handler : reply resending (t=fd185260, SIP/2.0 5 ... )
 1(29442) DEBUG: reply retransmitted. buf=fcf957a8: SIP/2.0 5..., shmem=fd186e60: SIP/2.0 5
 1(29442) DEBUG: add_to_tail_of_timer[6]: fd185314
 1(29442) DEBUG: retransmission_handler : done
 1(29442) DEBUG: timer routine:6,tl=fd1832b4 next=0
 1(29442) DEBUG: retransmission_handler : reply resending (t=fd183200, SIP/2.0 5 ... )
 1(29442) DEBUG: reply retransmitted. buf=fcf957a8: SIP/2.0 5..., shmem=fd1850e0: SIP/2.0 5
 1(29442) DEBUG: add_to_tail_of_timer[7]: fd1832b4
 1(29442) DEBUG: retransmission_handler : done
 1(29442) DEBUG: timer routine:6,tl=fd185314 next=0
 1(29442) DEBUG: retransmission_handler : reply resending (t=fd185260, SIP/2.0 5 ... )
 1(29442) DEBUG: reply retransmitted. buf=fcf957a8: SIP/2.0 5..., shmem=fd186e60: SIP/2.0 5
 1(29442) DEBUG: add_to_tail_of_timer[7]: fd185314
 1(29442) DEBUG: retransmission_handler : done
 1(29442) DEBUG: timer routine:7,tl=fd1832b4 next=0
 1(29442) DEBUG: retransmission_handler : reply resending (t=fd183200, SIP/2.0 5 ... )
 1(29442) DEBUG: reply retransmitted. buf=fcf957a8: SIP/2.0 5..., shmem=fd1850e0: SIP/2.0 5
 1(29442) DEBUG: add_to_tail_of_timer[7]: fd1832b4
 1(29442) DEBUG: retransmission_handler : done
 1(29442) DEBUG: timer routine:7,tl=fd185314 next=0
 1(29442) DEBUG: retransmission_handler : reply resending (t=fd185260, SIP/2.0 5 ... )
 1(29442) DEBUG: reply retransmitted. buf=fcf957a8: SIP/2.0 5..., shmem=fd186e60: SIP/2.0 5
 1(29442) DEBUG: add_to_tail_of_timer[7]: fd185314
 1(29442) DEBUG: retransmission_handler : done
 1(29442) DEBUG: timer routine:7,tl=fd1832b4 next=0
 1(29442) DEBUG: retransmission_handler : reply resending (t=fd183200, SIP/2.0 5 ... )
 1(29442) DEBUG: reply retransmitted. buf=fcf957a8: SIP/2.0 5..., shmem=fd1850e0: SIP/2.0 5
 1(29442) DEBUG: add_to_tail_of_timer[7]: fd1832b4
 1(29442) DEBUG: retransmission_handler : done
 1(29442) DEBUG: timer routine:7,tl=fd185314 next=0
 1(29442) DEBUG: retransmission_handler : reply resending (t=fd185260, SIP/2.0 5 ... )
 1(29442) DEBUG: reply retransmitted. buf=fcf957a8: SIP/2.0 5..., shmem=fd186e60: SIP/2.0 5
 1(29442) DEBUG: add_to_tail_of_timer[7]: fd185314
 1(29442) DEBUG: retransmission_handler : done
 1(29442) DEBUG: timer routine:7,tl=fd1832b4 next=0
 1(29442) DEBUG: retransmission_handler : reply resending (t=fd183200, SIP/2.0 5 ... )
 1(29442) DEBUG: reply retransmitted. buf=fcf957a8: SIP/2.0 5..., shmem=fd1850e0: SIP/2.0 5
 1(29442) DEBUG: add_to_tail_of_timer[7]: fd1832b4
 1(29442) DEBUG: retransmission_handler : done
 1(29442) DEBUG: timer routine:7,tl=fd185314 next=0
 1(29442) DEBUG: retransmission_handler : reply resending (t=fd185260, SIP/2.0 5 ... )
 1(29442) DEBUG: reply retransmitted. buf=fcf957a8: SIP/2.0 5..., shmem=fd186e60: SIP/2.0 5
 1(29442) DEBUG: add_to_tail_of_timer[7]: fd185314
 1(29442) DEBUG: retransmission_handler : done
 1(29442) DEBUG: timer routine:7,tl=fd1832b4 next=0
 1(29442) DEBUG: retransmission_handler : reply resending (t=fd183200, SIP/2.0 5 ... )
 1(29442) DEBUG: reply retransmitted. buf=fcf957a8: SIP/2.0 5..., shmem=fd1850e0: SIP/2.0 5
 1(29442) DEBUG: add_to_tail_of_timer[7]: fd1832b4
 1(29442) DEBUG: retransmission_handler : done
 1(29442) DEBUG: timer routine:7,tl=fd185314 next=0
 1(29442) DEBUG: retransmission_handler : reply resending (t=fd185260, SIP/2.0 5 ... )
 1(29442) DEBUG: reply retransmitted. buf=fcf957a8: SIP/2.0 5..., shmem=fd186e60: SIP/2.0 5
 1(29442) DEBUG: add_to_tail_of_timer[7]: fd185314
 1(29442) DEBUG: retransmission_handler : done
 1(29442) DEBUG: timer routine:7,tl=fd1832b4 next=0
 1(29442) DEBUG: retransmission_handler : reply resending (t=fd183200, SIP/2.0 5 ... )
 1(29442) DEBUG: reply retransmitted. buf=fcf957a8: SIP/2.0 5..., shmem=fd1850e0: SIP/2.0 5
 1(29442) DEBUG: add_to_tail_of_timer[7]: fd1832b4
 1(29442) DEBUG: retransmission_handler : done
 1(29442) DEBUG: timer routine:7,tl=fd185314 next=0
 1(29442) DEBUG: retransmission_handler : reply resending (t=fd185260, SIP/2.0 5 ... )
 1(29442) DEBUG: reply retransmitted. buf=fcf957a8: SIP/2.0 5..., shmem=fd186e60: SIP/2.0 5
 1(29442) DEBUG: add_to_tail_of_timer[7]: fd185314
 1(29442) DEBUG: retransmission_handler : done
 1(29442) DEBUG: timer routine:0,tl=fd1832c8 next=0
 1(29442) DEBUG: add_to_tail_of_timer[2]: fd183248
 1(29442) DEBUG: timer routine:7,tl=fd1832b4 next=0
 1(29442) DEBUG: timer routine:0,tl=fd185328 next=0
 1(29442) DEBUG: add_to_tail_of_timer[2]: fd1852a8
 1(29442) DEBUG: timer routine:7,tl=fd185314 next=0
 1(29442) DEBUG: timer routine:2,tl=fd183248 next=0
 1(29442) DEBUG: wait_handler : removing fd183200 from table 
 1(29442) DEBUG: delete transaction fd183200
 1(29442) DEBUG: wait_handler : done
 1(29442) DEBUG: timer routine:2,tl=fd1852a8 next=0
 1(29442) DEBUG: wait_handler : removing fd185260 from table 
 1(29442) DEBUG: delete transaction fd185260
 1(29442) DEBUG: wait_handler : done
^C 0(29441) INT received, program terminates
 1( 1( 1(29442) INFO: signal 15 received
 1(29442) Memory status (pkg):
 1(29442) fm_status (99f88):
 1(29442)  heap size= 1047440
 1(29442) dumping free list:
 1(29442) hash =   1 fragments no.:     3,
                 bucket size:         8 -         8 (first         8)
 1(29442) hash =   2 fragments no.:     1,
                 bucket size:        16 -        16 (first        16)
 1(29442) hash =   4 fragments no.:     1,
                 bucket size:        32 -        32 (first        32)
 1(29442) hash =  46 fragments no.:     1,
                 bucket size:       368 -       368 (first       368)
 1(29442) hash = 265 fragments no.:     1,
                 bucket size:    524288 -   1048576 (first   1042560)
 1(29442) TOTAL:      7 free fragments = 1043000 free bytes
 1(29442) -----------------------------
 0(29441) DEBUG: tm_shutdown : start
 0(29441) DEBUG: tm_shutdown : empting DELETE list
 0(29441) DEBUG: tm_shutdown : empting hash table
 0(29441) DEBUG: tm_shutdown: releasing timers
 0(29441) DEBUG: tm_shutdown : removing semaphores
 0(29441) DEBUG: tm_shutdown : done
 0(29441) Memory status (pkg):
 0(29441) fm_status (99f88):
 0(29441)  heap size= 1047440
 0(29441) dumping free list:
 0(29441) hash =   1 fragments no.:     7,
                 bucket size:         8 -         8 (first         8)
 0(29441) hash =   2 fragments no.:    31,
                 bucket size:        16 -        16 (first        16)
 0(29441) hash =   3 fragments no.:     7,
                 bucket size:        24 -        24 (first        24)
 0(29441) hash =   4 fragments no.:    38,
                 bucket size:        32 -        32 (first        32)
 0(29441) hash =   5 fragments no.:     2,
                 bucket size:        40 -        40 (first        40)
 0(29441) hash =   7 fragments no.:     1,
                 bucket size:        56 -        56 (first        56)
 0(29441) hash =   8 fragments no.:     1,
                 bucket size:        64 -        64 (first        64)
 0(29441) hash =   9 fragments no.:     1,
                 bucket size:        72 -        72 (first        72)
 0(29441) hash =  15 fragments no.:     2,
                 bucket size:       120 -       120 (first       120)
 0(29441) hash =  17 fragments no.:     1,
                 bucket size:       136 -       136 (first       136)
 0(29441) hash =  42 fragments no.:     1,
                 bucket size:       336 -       336 (first       336)
 0(29441) hash =  68 fragments no.:     1,
                 bucket size:       544 -       544 (first       544)
 0(29441) hash =  71 fragments no.:     1,
                 bucket size:       568 -       568 (first  2( 2( 2(29443) INFO: signal 15 received
 2(29443) Memory status (pkg):
 2(29443) fm_status (99f88):
 2(29443)  heap size= 1047440
 2(29443) dumping free list:
 2(29443) hash =   1 fragments no.:     3,
                 bucket size:         8 -         8 (first         8)
 2(29443) hash =   2 fragments no.:     1,
                 bucket size:        16 -        16 (first        16)
 2(29443) hash =   4 fragments no.:     1,
                 bucket size:        32 -        32 (first        32)
 2(29443) hash =  46 fragments no.:     1,
                 bucket size:       368 -       368 (first       368)
 2(29443) hash = 265 fragments no.:     1,
                 bucket size:    524288 -   1048576 (first   1042560)
 2(29443) TOTAL:      7 free fragments = 1043000 free bytes
 2(29443) -----------------------------
      568)
 0(29441) hash =  93 fragments no.:     1,
                 bucket size:       744 -       744 (first       744)
 0(29441) hash = 122 fragments no.:     1,
                 bucket size:       976 -       976 (first       976)
 0(29441) hash = 128 fragments no.:     1,
                 bucket size:      1024 -      1024 (first      1024)
 0(29441) hash = 265 fragments no.:     1,
                 bucket size:    524288 -   1048576 (first   1036808)
 0(29441) TOTAL:     98 free fragments = 1043584 free bytes
 0(29441) -----------------------------
 0(29441) Memory status (shm):
 0(29441) fm_status (fd000000):
 0(29441)  heap size= 33553296
 0(29441) dumping free list:
 0(29441) hash =   1 fragments no.:     4,
                 bucket size:         8 -         8 (first         8)
 0(29441) hash =   2 fragments no.:     1,
                 bucket size:        16 -        16 (first        16)
 0(29441) hash =   5 fragments no.:     3,
                 bucket size:        40 -        40 (first        40)
 0(29441) hash =   6 fragments no.:     3,
                 bucket size:        48 -        48 (first        48)
 0(29441) hash =  41 fragments no.:     2,
                 bucket size:       328 -       328 (first       328)
 0(29441) hash =  48 fragments no.:     1,
                 bucket size:       384 -       384 (first       384)
 0(29441) hash =  91 fragments no.:     1,
                 bucket size:       728 -       728 (first       728)
 0(29441) hash = 122 fragments no.:     2,
                 bucket size:       976 -       976 (first       976)
 0(29441) hash = 130 fragments no.:     1,
                 bucket size:      1040 -      1040 (first      1040)
 0(29441) hash = 210 fragments no.:     1,
                 bucket size:      1680 -      1680 (first      1680)
 0(29441) hash = 257 fragments no.:     4,
                 bucket size:      2048 -      4096 (first      3080)
 0(29441) hash = 258 fragments no.:     2,
                 bucket size:      4096 -      8192 (first      4096)
 0(29441) hash = 266 fragments no.:     1,
                 bucket size:   1048576 -   2097152 (first   1572864)
 0(29441) hash = 270 fragments no.:     1,
                 bucket size:  16777216 -  33554432 (first  31952928)
 0(29441) TOTAL:     27 free fragments = 33553072 free bytes
 0(29441) -----------------------------
 0(29441) shm_mem_destroy
 0(29441) destroying the shared memory lock
 0(29441) Thank you for flying ser
# 
script done on Tue 30 Mar 2004 05:11:06 PM CST