Re: [Serusers] Not Recognizing ACK

Running SER 0.8.12 on Solaris 8 -SPARC with MySQL installed. The issue that I'm running into is that when the originating GW receives a response and generates an ACK the SER doesn't seem to stop the timer for resending the message. If you look in the log, you can see where the server receives it, but the server resends the same response as if the ACK was ignored. It the attached case a 503 response is sent back, but the same situation occurs when other responses are sent. Thanks, Mike

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: &#39;58282eed-0(a)10.31.14.200&#39; 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: &#39;58282eed-0(a)10.31.14.200&#39; 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: &#39;58282eed-29441(a)10.31.14.200&#39; 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(a)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(a)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

_______________________________________________ Serusers mailing list serusers(a)lists.iptel.org http://lists.iptel.org/mailman/listinfo/serusers