reduction of lock/malloc calls

Makefile.defs

@@ -47,12 +47,14 @@ ARCH = $(shell uname -s)
 # -DVQ_MALLOC
 #		additional option to PKG_MALLOC which utilizes a fater then
 #		qm version
+# -DDBG_MALLOC
+#		issues additional debugging information if lock/unlock is called
 #
 
 DEFS+= -DNAME='"$(NAME)"' -DVERSION='"$(RELEASE)"' -DARCH='"$(ARCH)"' \
 	 -DDNS_IP_HACK  -DPKG_MALLOC -DSHM_MEM  -DSHM_MMAP \
 	-DEXTRA_DEBUG \
-	-DVQ_MALLOC  #-DSTATS
+	-DDBG_QM_MALLOC -DVQ_MALLOC  -DDBG_LOCK  #-DSTATS
 	  #-DDBG_QM_MALLOC #-DVQ_MALLOC #-DNO_DEBUG
 	  #-DNO_DEBUG #-DDBG_QM_MALLOC
 #-DEXTRA_DEBUG

action.c

@@ -395,7 +395,8 @@ int run_actions(struct action* a, struct sip_msg* msg)
 	}
 		
 	if (a==0){
-		LOG(L_ERR, "WARNING: run_actions: null action list\n");
+		LOG(L_ERR, "WARNING: run_actions: null action list (rec_level=%d)\n", 
+			rec_lev);
 		ret=0;
 	}
 

main.c

@@ -489,6 +489,7 @@ int main(int argc, char** argv)
 					printf("flags: %s\n", flags );
 					print_ct_constants();
 					printf("%s\n",id);
+					printf("%s compiled on %s at %s\n", __FILE__, __DATE__, __TIME__ );
 					exit(0);
 					break;
 			case 'h':

mem/shm_mem.c

@@ -47,7 +47,111 @@ static void* shm_mempool=(void*)-1;
 	struct qm_block* shm_block;
 #endif
 
+#define sh_realloc(_p, _size) ({ \
+		char *_c; \
+		shm_lock(); \
+		shm_free_unsafe( (_p) ); \
+		_c=shm_malloc_unsafe( (_size) ); \
+		shm_unlock(); \
+		_c; })
 
+/* look at a buffer if there is perhaps enough space for the new size
+   (It is benefitial to do so because vq_malloc is pretty stateful
+    and if we ask for a new buffer size, we can still make it happy
+    with current buffer); if so, we return current buffer again;
+    otherwise, we free it, allocate a new one and return it; no
+    guarantee for buffer content; if allocation fails, we return
+    NULL
+*/
+#ifdef DBG_QM_MALLOC
+void* _shm_resize( void* p, unsigned int s, char* file, char* func, unsigned int line)
+#else
+void* _shm_resize( void* p , unsigned int s)
+#endif
+{
+	char *c;
+#ifdef VQ_MALLOC
+	struct vqm_frag *f;
+#else
+#	warning shm_resize performs suboptimally without VQ_MALLOC!
+#endif
+
+	if (p==0) {
+		DBG("WARNING:vqm_resize: resize(0) called\n");
+		return shm_malloc( s );
+	}
+
+#	ifdef VQ_MALLOC
+	f=(struct  vqm_frag*) ((char*)p-sizeof(struct vqm_frag));
+#	ifdef DBG_QM_MALLOC
+	DBG("_shm_resize(%x, %d), called from %s: %s(%d)\n",  p, s, file, func, line);
+	VQM_DEBUG_FRAG(shm_block, f);
+	if (p>(void *)shm_block->core_end || p<(void*)shm_block->init_core){
+		LOG(L_CRIT, "BUG: vqm_free: bad pointer %x (out of memory block!) - "
+				"aborting\n", p);
+		abort();
+	}
+#	endif
+	if (s <= f->size-VQM_OVERHEAD) {
+#		ifdef DBG_QM_MALLOC
+		DBG("DEBUG: happy guy -- you reused a memory fragment!\n");
+#		endif
+		return p;
+	};
+#endif
+	/* we can't make the request happy with current size */
+	return sh_realloc( p, s ); 
+}
+
+
+inline void shm_lock()
+{
+	struct sembuf sop;
+	
+	sop.sem_num=0;
+	sop.sem_op=-1; /*down*/
+	sop.sem_flg=0 /*SEM_UNDO*/;
+again:
+	semop(shm_semid, &sop, 1);
+#if 0
+	switch(ret){
+		case 0: /*ok*/
+			break;
+		case EINTR: /*interrupted by signal, try again*/
+			DBG("sh_lock: interrupted by signal, trying again...\n");
+			goto again;
+		default:
+			LOG(L_ERR, "ERROR: sh_lock: error waiting on semaphore: %s\n",
+					strerror(errno));
+	}
+#endif
+}
+
+
+
+inline void shm_unlock()
+{
+	struct sembuf sop;
+	
+	sop.sem_num=0;
+	sop.sem_op=1; /*up*/
+	sop.sem_flg=0 /*SEM_UNDO*/;
+again:
+	semop(shm_semid, &sop, 1);
+#if 0
+	/*should ret immediately*/
+	switch(ret){
+		case 0: /*ok*/
+			break;
+		case EINTR: /*interrupted by signal, try again*/
+			DBG("sh_lock: interrupted by signal, trying again...\n");
+			goto again;
+		default:
+			LOG(L_ERR, "ERROR: sh_lock: error waiting on semaphore: %s\n",
+					strerror(errno));
+	}
+#endif
+}
 
 /* ret -1 on erro*/
 int shm_mem_init()

mem/shm_mem.h

@@ -44,113 +44,61 @@ extern int shm_semid;
 
 int shm_mem_init();
 void shm_mem_destroy();
+inline void shm_lock();
+inline void shm_unlock();
 
 
 
-inline static void shm_lock()
-{
-	struct sembuf sop;
-	
-	sop.sem_num=0;
-	sop.sem_op=-1; /*down*/
-	sop.sem_flg=0 /*SEM_UNDO*/;
-again:
-	semop(shm_semid, &sop, 1);
-#if 0
-	switch(ret){
-		case 0: /*ok*/
-			break;
-		case EINTR: /*interrupted by signal, try again*/
-			DBG("sh_lock: interrupted by signal, trying again...\n");
-			goto again;
-		default:
-			LOG(L_ERR, "ERROR: sh_lock: error waiting on semaphore: %s\n",
-					strerror(errno));
-	}
-#endif
-}
-
-
-
-inline static void shm_unlock()
-{
-	struct sembuf sop;
-	
-	sop.sem_num=0;
-	sop.sem_op=1; /*up*/
-	sop.sem_flg=0 /*SEM_UNDO*/;
-again:
-	semop(shm_semid, &sop, 1);
-#if 0
-	/*should ret immediately*/
-	switch(ret){
-		case 0: /*ok*/
-			break;
-		case EINTR: /*interrupted by signal, try again*/
-			DBG("sh_lock: interrupted by signal, trying again...\n");
-			goto again;
-		default:
-			LOG(L_ERR, "ERROR: sh_lock: error waiting on semaphore: %s\n",
-					strerror(errno));
-	}
-#endif
-}
-
-
 
 #ifdef DBG_QM_MALLOC
-#define shm_malloc(size) \
+
+#define shm_malloc_unsafe(_size ) \
+	MY_MALLOC(shm_block, (_size), __FILE__, __FUNCTION__, __LINE__ )
+#define shm_malloc(_size) \
 ({\
 	void *p;\
 	\
-	/*if (shm_lock()==0){*/\
-		shm_lock();\
-		p=MY_MALLOC(shm_block, (size), __FILE__, __FUNCTION__, __LINE__);\
-		shm_unlock();\
-	/* \
-	}else{ \
-		p=0;\
-	}*/ \
-	 p; \
+	shm_lock();\
+	p=shm_malloc_unsafe( (_size) );\
+	shm_unlock();\
+	p; \
 })
 
-
-
-#define shm_free(p) \
+#define shm_free_unsafe( _p  ) \
+	MY_FREE( shm_block, (_p), __FILE__, __FUNCTION__, __LINE__ )
+#define shm_free(_p) \
 do { \
 		shm_lock(); \
-		MY_FREE(shm_block, (p), __FILE__, __FUNCTION__, __LINE__); \
+		shm_free_unsafe( (_p)); \
 		shm_unlock(); \
 }while(0)
 
+#define shm_resize(_p, _s ) \
+	_shm_resize( (_p), (_s),   __FILE__, __FUNCTION__, __LINE__)
 
 #else
 
-
+#define shm_malloc_unsafe(_size) MY_MALLOC(shm_block, (_size))
 #define shm_malloc(size) \
 ({\
 	void *p;\
 	\
-	/*if (shm_lock()==0){*/\
 		shm_lock();\
-		p=MY_MALLOC(shm_block, (size));\
+		p=shm_malloc_unsafe(size); \
 		shm_unlock();\
-	/* \
-	}else{ \
-		p=0;\
-	}*/ \
 	 p; \
 })
 
 
-
-#define shm_free(p) \
+#define shm_free_unsafe( _p ) MY_FREE(shm_block, (_p))
+#define shm_free(_p) \
 do { \
 		shm_lock(); \
-		MY_FREE(shm_block, (p)); \
+		shm_free_unsafe( _p ); \
 		shm_unlock(); \
 }while(0)
 
+#define shm_resize(_p, _s) _shm_resize( (_p), (_s))
 
 #endif
 
@@ -163,7 +111,7 @@ do { \
 }while(0)
 
 
-	
+
 
 #endif
 

mem/vq_malloc.c

@@ -85,7 +85,7 @@ void my_assert( int assertation, int line, char *file, char *function )
 }
 
 #ifdef DBG_QM_MALLOC
-static  void vqm_debug_frag(struct vqm_block* qm, struct vqm_frag* f)
+void vqm_debug_frag(struct vqm_block* qm, struct vqm_frag* f)
 {
 
 	int r;
@@ -110,15 +110,14 @@ static  void vqm_debug_frag(struct vqm_block* qm, struct vqm_frag* f)
    and changed the demanded size to size really used including all
    possible overhead
  */
-unsigned char size2bucket( struct vqm_block* qm, int *size )
+unsigned char size2bucket( struct vqm_block* qm, int *size  )
 {
 	unsigned char b;	
 	unsigned int real_size;
 	unsigned int exceeds;
 
+	real_size = *size+ VQM_OVERHEAD;
 
-	real_size = *size+ sizeof(struct vqm_frag)+
-			sizeof(struct vqm_frag_end);
 #ifdef DBG_QM_MALLOC
 	real_size+=END_CHECK_PATTERN_LEN;
 #endif
@@ -307,9 +306,6 @@ void* vqm_malloc(struct vqm_block* qm, unsigned int size)
 	return (char*)new_chunk+sizeof(struct vqm_frag);
 }
 
-
-
-
 #ifdef DBG_QM_MALLOC
 void vqm_free(struct vqm_block* qm, void* p, char* file, char* func, 
 				unsigned int line)

mem/vq_malloc.h

@@ -35,16 +35,18 @@
 
 
 #ifdef DBG_QM_MALLOC
-#define ST_CHECK_PATTERN   	0xf0f0f0f0
-#define END_CHECK_PATTERN  	"sExP"
-#define END_CHECK_PATTERN_LEN 	4
-
-#define VQM_DEBUG_FRAG(qm, f) vqm_debug_frag( (qm), (f))
+#	define ST_CHECK_PATTERN   	0xf0f0f0f0
+#	define END_CHECK_PATTERN  	"sExP"
+#	define END_CHECK_PATTERN_LEN 	4
+#	define VQM_OVERHEAD (sizeof(struct vqm_frag)+ sizeof(struct vqm_frag_end)+END_CHECK_PATTERN_LEN)
+#	define VQM_DEBUG_FRAG(qm, f) vqm_debug_frag( (qm), (f))
 #else
-#define VQM_DEBUG_FRAG(qm, f)
+#	define VQM_DEBUG_FRAG(qm, f)
+#	define VQM_OVERHEAD (sizeof(struct vqm_frag)+ sizeof(struct vqm_frag_end))
 #endif
 
 
+
 struct vqm_frag {
 	/* XXX */
 	/* total chunk size including all overhead/bellowfoot/roundings/etc */
@@ -113,14 +115,10 @@ struct vqm_block* vqm_malloc_init(char* address, unsigned int size);
 #ifdef DBG_QM_MALLOC
 void* vqm_malloc(struct vqm_block*, unsigned int size, char* file, char* func, 
 					unsigned int line);
-#else
-void* vqm_malloc(struct vqm_block*, unsigned int size);
-#endif
-
-#ifdef DBG_QM_MALLOC
 void  vqm_free(struct vqm_block*, void* p, char* file, char* func, 
 				unsigned int line);
 #else
+void* vqm_malloc(struct vqm_block*, unsigned int size);
 void  vqm_free(struct vqm_block*, void* p);
 #endif
 

modules/tm/config.h

@@ -33,4 +33,10 @@
 #define RETR_T1  		1
 #define RETR_T2  		4
 
+/* when first reply is sent, this additional space is allocated so that
+   one does not have to reallocate share memory when the message is
+   replaced by a subsequent, longer message
+*/
+#define REPLY_OVERBUFFER_LEN 160
+
 #endif

modules/tm/h_table.c

@@ -19,10 +19,11 @@ void free_cell( struct cell* dead_cell )
 	DBG("DEBUG: free_cell: start\n");
 	/* UA Server */
 	DBG("DEBUG: free_cell: inbound request %p\n",dead_cell->inbound_request);
+	shm_lock();
 	if ( dead_cell->inbound_request )
-		sip_msg_free( dead_cell->inbound_request );
+		sip_msg_free_unsafe( dead_cell->inbound_request );
 	DBG("DEBUG: free_cell: outbound response %p\n",dead_cell->outbound_response);
-	if (b=dead_cell->outbound_response.retr_buffer) sh_free( b );
+	if (b=dead_cell->outbound_response.retr_buffer) shm_free_unsafe( b );
 
 	/* UA Clients */
 	for ( i =0 ; i<dead_cell->nr_of_outgoings;  i++ )
@@ -31,19 +32,22 @@ void free_cell( struct cell* dead_cell )
 		DBG("DEBUG: free_cell: outbound_request[%d] %p\n",i,dead_cell->outbound_request[i]);
 		if ( rb=dead_cell->outbound_request[i] )
       		{
-			if (rb->retr_buffer) sh_free( rb->retr_buffer );
+/*
+			if (rb->retr_buffer) shm_free( rb->retr_buffer );
 	 		dead_cell->outbound_request[i] = NULL;
-         		sh_free( rb );
+*/
+         		shm_free_unsafe( rb );
       		}
       		/* outbound requests*/
       		DBG("DEBUG: free_cell: inbound_response[%d] %p\n",i,dead_cell->inbound_response[i]);
       		if ( dead_cell -> inbound_response[i] )
-         		sip_msg_free( dead_cell->inbound_response[i] );
+         		sip_msg_free_unsafe( dead_cell->inbound_response[i] );
    	}
    	/* mutex */
    	/* release_cell_lock( dead_cell ); */
    	/* the cell's body */
-   	sh_free( dead_cell );
+   	shm_free_unsafe( dead_cell );
+	shm_unlock();
    	DBG("DEBUG: free_cell: done\n");
 }
 

modules/tm/lock.c

@@ -172,42 +172,56 @@ void lock_cleanup()
 }
 
 
+
+
 /* lock sempahore s */
-int lock( ser_lock_t s )
+#ifdef DBG_LOCK
+inline int _lock( ser_lock_t s , char *file, char *function, unsigned int line )
+#else
+inline int _lock( ser_lock_t s )
+#endif
 {
-	//DBG("DEBUG: lock: entering lock\n");
+#ifdef DBG_LOCK
+	DBG("DEBUG: lock : entered from %s , %s(%d)\n", function, file, line );
+#endif
 	return change_semaphore( s, -1 );
-	//DBG("DEBUG: lock: leaving lock\n");
 }
 
-int unlock( ser_lock_t s )
+#ifdef DBG_LOCK
+inline int _unlock( ser_lock_t s, char *file, char *function, unsigned int line )
+#else
+inline int _unlock( ser_lock_t s )
+#endif
 {
-	//DBG("DEBUG: unlock: entering unlock\n");
+#ifdef DBG_LOCK
+	DBG("DEBUG: lock : entered from %s, %s:%d\n", file, function, line );
+#endif
 	return change_semaphore( s, +1 );
-	//DBG("DEBUG: unlock: leaving unlock\n");
 }
 
 
 int change_semaphore( ser_lock_t s  , int val )
 {
-   struct sembuf pbuf;
-   int r;
+	struct sembuf pbuf;
+	int r;
 
-   pbuf.sem_num = s.semaphore_index ;
-   pbuf.sem_op =val;
-   pbuf.sem_flg = 0;
+	pbuf.sem_num = s.semaphore_index ;
+	pbuf.sem_op =val;
+	pbuf.sem_flg = 0;
 
 tryagain:
-   r=semop( s.semaphore_set, &pbuf ,  1 /* just 1 op */ );
+	r=semop( s.semaphore_set, &pbuf ,  1 /* just 1 op */ );
 
-   if (r==-1) {
-	if (errno=EINTR) {
-		DBG("signal received in a semaphore\n");
-		goto tryagain;
-	} else LOG(L_ERR, "ERROR: change_semaphore: %s\n", strerror(errno));
+	if (r==-1) {
+		if (errno=EINTR) {
+			DBG("signal received in a semaphore\n");
+			goto tryagain;
+		} else LOG(L_ERR, "ERROR: change_semaphore: %s\n", strerror(errno));
     }
    return r;
 }
+
+
 /*
 int init_cell_lock( struct cell *cell )
 {

modules/tm/lock.h

@@ -30,8 +30,19 @@ int lock_initialize();
 int init_semaphore_set( int size );
 void lock_cleanup();
 
-int lock( ser_lock_t s );
-int unlock( ser_lock_t s );
+
+#ifdef DBG_LOCK
+int _lock( ser_lock_t s , char *file, char *function, unsigned int line );
+int _unlock( ser_lock_t s, char *file, char *function, unsigned int line );
+#	define lock(_s) _lock( (_s), __FILE__, __FUNCTION__, __LINE__ )
+#	define unlock(_s) _unlock( (_s), __FILE__, __FUNCTION__, __LINE__ )
+#else
+int _lock( ser_lock_t s );
+int _unlock( ser_lock_t s );
+#	define lock(_s) _lock( (_s) )
+#	define unlock(_s) _unlock( (_s) )
+#endif
+
 int change_semaphore( ser_lock_t s  , int val );
 
 int init_cell_lock( struct cell *cell );

modules/tm/sip_msg.c

@@ -693,7 +693,3 @@ struct via_body* via_body_cloner_2( char* new_buf , char *org_buf , struct via_b
    return new_via;
 }
 
-void sip_msg_free_2(struct sip_msg* msg)
-{
-   sh_free( (char*)msg );
-}

modules/tm/sip_msg.h

@@ -13,14 +13,15 @@
 #define sip_msg_cloner(p_msg) \
     sip_msg_cloner_2(p_msg)
 
-#define sip_msg_free(p_msg) \
-    sip_msg_free_2(p_msg)
+#define sip_msg_free(_p_msg) shm_free( (_p_msg ))
+#define sip_msg_free_unsafe(_p_msg) shm_free_unsafe( (_p_msg) )
+/*    sip_msg_free_2(p_msg) */
 
 
 struct sip_msg*  sip_msg_cloner_1( struct sip_msg *org_msg );
 struct sip_msg*  sip_msg_cloner_2( struct sip_msg *org_msg );
 void                     sip_msg_free_1( struct sip_msg *org_msg );
-void                     sip_msg_free_2( struct sip_msg *org_msg );
+/* void                     sip_msg_free_2( struct sip_msg *org_msg ); */
 
 
 #endif

modules/tm/t_funcs.c

@@ -191,10 +191,12 @@ int t_forward( struct sip_msg* p_msg , unsigned int dest_ip_param , unsigned int
 	unsigned int dest_port  = dest_port_param;
 	int	branch;
 	unsigned int len;
-   	char               *buf;
+   	char               *buf, *shbuf;
 	struct retrans_buff *rb;
+	
 
 	buf=NULL;
+	shbuf = NULL;
 	branch = 0;	/* we don't do any forking right now */
 
 	/* it's about the same transaction or not? */
@@ -253,36 +255,42 @@ int t_forward( struct sip_msg* p_msg , unsigned int dest_ip_param , unsigned int
 				"nothing to CANCEL\n");
             			return 1;
          		}
-      		}/* end special case CANCEL*/
+      	}/* end special case CANCEL*/
+
+		if ( add_branch_label( T, T->inbound_request , branch )==-1) 
+			goto error;
+		if ( add_branch_label( T, p_msg , branch )==-1) 
+			goto error;
+		if ( !(buf = build_req_buf_from_sip_req  ( p_msg, &len))) 
+			goto error;
 
 		/* allocates a new retrans_buff for the outbound request */
 		DBG("DEBUG: t_forward: building outbound request\n");
+		shm_lock();
 		T->outbound_request[branch] = rb = 
-			(struct retrans_buff*)sh_malloc( sizeof(struct retrans_buff) );
+			(struct retrans_buff*)shm_malloc_unsafe( sizeof(struct retrans_buff)  );
 		if (!rb)
 		{
 			LOG(L_ERR, "ERROR: t_forward: out of shmem\n");
+			shm_unlock();
+			goto error;
+		}
+		shbuf = (char *) shm_malloc_unsafe( len );
+		if (!shbuf)
+		{ 
+			LOG(L_ERR, "ERROR: t_forward: out of shmem buffer\n");
+			shm_unlock();
 			goto error;
 		}
+		shm_unlock();
 		memset( rb , 0 , sizeof (struct retrans_buff) );
+		rb->retr_buffer = shbuf;
 		rb->retr_timer.payload =  rb;
 		rb->fr_timer.payload =  rb;
 		rb->to.sin_family = AF_INET;
 		rb->my_T =  T;
 		T->nr_of_outgoings = 1;
-
-		if ( add_branch_label( T, T->inbound_request , branch )==-1) 
-			goto error;
-		if ( add_branch_label( T, p_msg , branch )==-1) 
-			goto error;
-		if ( !(buf = build_req_buf_from_sip_req  ( p_msg, &len))) 
-			goto error;
 		rb->bufflen = len ;
-		if ( !(rb->retr_buffer = (char*)sh_malloc( len ))) 
-		{
-			LOG(L_ERR, "ERROR: t_forward: shmem allocation failed\n");
-			goto error;
-		}
 		memcpy( rb->retr_buffer , buf , len );
 		free( buf ) ; buf=NULL;
 
@@ -330,9 +338,9 @@ int t_forward( struct sip_msg* p_msg , unsigned int dest_ip_param , unsigned int
    return 1;
 
 error:
-	if ( rb && rb->retr_buffer) sh_free( rb->retr_buffer );
+	if (shbuf) shm_free(shbuf);
 	if (rb) {
-		sh_free(rb);
+		shm_free(rb);
 		T->outbound_request[branch]=NULL;
 	}
 	if (buf) free( buf );
@@ -582,10 +590,9 @@ int t_unref( struct sip_msg* p_msg, char* foo, char* bar )
   */
 int t_send_reply(  struct sip_msg* p_msg , unsigned int code , char * text )
 {
-	unsigned int len;
+	unsigned int len, buf_len;
 	char * buf;
 	struct retrans_buff *rb;
-	char *b;
 
 	DBG("DEBUG: t_send_reply: entered\n");
 	if (t_check( p_msg , 0 )==-1) return -1;
@@ -628,15 +635,16 @@ int t_send_reply(  struct sip_msg* p_msg , unsigned int code , char * text )
 		goto error;
 	}
 
-	if (! (b = (char*)sh_malloc( len )))
+	/* if this is a first reply (?100), longer replies will probably follow;
+       try avoiding shm_resize by higher buffer size
+    */
+	buf_len = rb->retr_buffer ? len : len + REPLY_OVERBUFFER_LEN;
+
+	if (! (rb->retr_buffer = (char*)shm_resize( rb->retr_buffer, buf_len )))
 	{
 		LOG(L_ERR, "ERROR: t_send_reply: cannot allocate shmem buffer\n");
 		goto error2;
 	}
-	/* if present, remove previous message */
-	if (  rb->retr_buffer)
-		sh_free( rb->retr_buffer );
-	rb->retr_buffer   = b;
 	rb->bufflen = len ;
 	memcpy( rb->retr_buffer , buf , len );
 	free( buf ) ;
@@ -666,9 +674,8 @@ error:
 int push_reply_from_uac_to_uas( struct cell* trans , unsigned int branch )
 {
 	char *buf;
-	unsigned int len;
+	unsigned int len, buf_len;
 	struct retrans_buff *rb;
-	char *b;
 
 	DBG("DEBUG: push_reply_from_uac_to_uas: start\n");
 	rb= & trans->outbound_response;
@@ -700,14 +707,16 @@ int push_reply_from_uac_to_uas( struct cell* trans , unsigned int branch )
 			"no shmem for outbound reply buffer\n");
 		goto error;
 	}
-	if ( !(b = (char*)sh_malloc( len ))) {
-		LOG(L_ERR, "ERROR: push_reply_from_uac_to_uas: "
-			"no memory to allocate retr_buffer\n");
+
+	/* if this is a first reply (?100), longer replies will probably follow;
+       try avoiding shm_resize by higher buffer size
+    */
+	buf_len = rb->retr_buffer ? len : len + REPLY_OVERBUFFER_LEN;
+	if (! (rb->retr_buffer = (char*)shm_resize( rb->retr_buffer, buf_len )))
+	{
+		LOG(L_ERR, "ERROR: t_send_reply: cannot allocate shmem buffer\n");
 		goto error1;
 	}
-	if (  rb->retr_buffer ) 
-		sh_free(  rb->retr_buffer ) ;  
-	rb->retr_buffer = b;
 	rb->bufflen = len ;
    	memcpy( rb->retr_buffer , buf , len );
    	free( buf ) ;
@@ -966,8 +975,8 @@ int t_build_and_send_ACK( struct cell *Trans, unsigned int branch, struct sip_ms
       else if ( hdr->type==HDR_TO )
                  len += ((r_msg->to->body.s+r_msg->to->body.len ) - r_msg->to->name.s ) + CRLF_LEN ;
 
-   /* CSEQ method : from INVITE-> ACK, don't count CRLF twice*/
-   len -= 3 + 2 ;
+   /* CSEQ method : from INVITE-> ACK */
+   len -= 3  ;
    /* end of message */
    len += CRLF_LEN; /*new line*/
 
@@ -1048,6 +1057,58 @@ error:
 }
 
 
+void delete_cell( struct cell *p_cell )
+{
+#ifdef EXTRA_DEBUG
+	int i;
+
+	if (is_in_timer_list2(& p_cell->wait_tl )) {
+		LOG( L_ERR, "ERROR: transaction %p scheduled for deletion and still on WAIT\n",
+			p_cell);
+		abort();
+	}
+	if (is_in_timer_list2(& p_cell->outbound_response.retr_timer )) {
+		LOG( L_ERR, "ERROR: transaction %p scheduled for deletion and still on RETR (rep)\n",
+			p_cell);
+		abort();
+	}
+	if (is_in_timer_list2(& p_cell->outbound_response.fr_timer )) {
+		LOG( L_ERR, "ERROR: transaction %p scheduled for deletion and still on FR (rep)\n",
+			p_cell);
+		abort();
+	}
+	for (i=0; i<p_cell->nr_of_outgoings; i++) {
+		if (is_in_timer_list2(& p_cell->outbound_request[i]->retr_timer)) {
+			LOG( L_ERR, "ERROR: transaction %p scheduled for deletion and still on RETR (req %d)\n",
+			p_cell, i);
+			abort();
+		}
+		if (is_in_timer_list2(& p_cell->outbound_request[i]->fr_timer)) {
+			LOG( L_ERR, "ERROR: transaction %p scheduled for deletion and still on FR (req %d)\n",
+			p_cell, i);
+			abort();
+		}
+	}
+#endif
+	/* still in use ... don't delete */
+	if ( p_cell->ref_counter ) {
+#ifdef	EXTRA_DEBUG
+		if (p_cell->ref_counter>1) {
+			DBG("DEBUG: while debugging with a single process, ref_count > 1\n");
+			DBG("DEBUG: transaction =%p\n", p_cell );
+			abort();
+		}
+#endif
+		DBG("DEBUG: delete_cell: t=%p post for delete (%d)\n",
+			p_cell,p_cell->ref_counter);
+		/* it's added to del list for future del */
+		set_timer( hash_table, &(p_cell->dele_tl), DELETE_LIST );
+	} else {
+		DBG("DEBUG: delete_handler : delete transaction %p\n", p_cell );
+		free_cell( p_cell );
+	}
+}
+
 
 /*---------------------TIMEOUT HANDLERS--------------------------*/
 
@@ -1147,75 +1208,23 @@ void wait_handler( void *attr)
 #ifdef EXTRA_DEBUG
 	p_cell->damocles = 1;
 #endif
-	set_timer( hash_table, &(p_cell->dele_tl), DELETE_LIST );
+	delete_cell( p_cell );
 	DBG("DEBUG: wait_handler : done\n");
 }
 
 
-
-
 void delete_handler( void *attr)
 {
 	struct cell *p_cell = (struct cell*)attr;
 
+	DBG("DEBUG: delete_handler : removing %p \n", p_cell );
 #ifdef EXTRA_DEBUG
-	int i;
 	if (p_cell->damocles==0) {
 		LOG( L_ERR, "ERROR: transaction %p not scheduled for deletion and called from DELETE timer\n",
 			p_cell);
 		abort();
 	}	
-	if (is_in_timer_list2(& p_cell->wait_tl )) {
-		LOG( L_ERR, "ERROR: transaction %p scheduled for deletion and still on WAIT\n",
-			p_cell);
-		abort();
-	}
-	if (is_in_timer_list2(& p_cell->outbound_response.retr_timer )) {
-		LOG( L_ERR, "ERROR: transaction %p scheduled for deletion and still on RETR (rep)\n",
-			p_cell);
-		abort();
-	}
-	if (is_in_timer_list2(& p_cell->outbound_response.fr_timer )) {
-		LOG( L_ERR, "ERROR: transaction %p scheduled for deletion and still on FR (rep)\n",
-			p_cell);
-		abort();
-	}
-	for (i=0; i<p_cell->nr_of_outgoings; i++) {
-		if (is_in_timer_list2(& p_cell->outbound_request[i]->retr_timer)) {
-			LOG( L_ERR, "ERROR: transaction %p scheduled for deletion and still on RETR (req %d)\n",
-			p_cell, i);
-			abort();
-		}
-		if (is_in_timer_list2(& p_cell->outbound_request[i]->fr_timer)) {
-			LOG( L_ERR, "ERROR: transaction %p scheduled for deletion and still on FR (req %d)\n",
-			p_cell, i);
-			abort();
-		}
-	}
-
-#endif
-
-	/* the transaction is already removed from DEL_LIST by the timer */
-	/* if is not refenceted -> is deleted*/
-	if ( p_cell->ref_counter==0 )
-	{
-		DBG("DEBUG: delete_handler : delete transaction %p\n", p_cell );
-		free_cell( p_cell );
-	} else {
-#ifdef	EXTRA_DEBUG
-		if (p_cell->ref_counter>1) {
-			DBG("DEBUG: while debugging with a single process, ref_count > 1\n");
-			DBG("DEBUG: transaction =%p\n", p_cell );
-			abort();
-		}
 #endif
-		DBG("DEBUG: delete_handler: t=%p post for delete (%d)\n",
-			p_cell,p_cell->ref_counter);
-		/* else it's readded to del list for future del */
-		set_timer( hash_table, &(p_cell->dele_tl), DELETE_LIST );
-    }
+	delete_cell( p_cell );
     DBG("DEBUG: delete_handler : done\n");
 }
-
-
-

modules/tm/timer.c

@@ -100,6 +100,12 @@ struct timer_link  *check_and_split_time_list( struct timer *timer_list, int tim
 	struct timer_link *tl , *tmp , *end, *ret;
 
 	//DBG("DEBUG : check_and_split_time_list: start\n");
+
+	/* quick check whether it is worth entering the lock */
+	if (timer_list->first_tl.next_tl==&timer_list->last_tl ||
+		timer_list->first_tl.next_tl->time_out > time )
+			return NULL;
+
 	/* the entire timer list is locked now -- noone else can manipulate it */
 	lock( timer_list->mutex );
 

test/tx.cfg

@@ -4,15 +4,17 @@
 # $ID: $
 #
 
-debug=9          # debug level (cmd line: -dddddddddd)
+debug=1          # debug level (cmd line: -dddddddddd)
+fork=yes          # (cmd. line: -D)
+#fork=no
+log_stderror=yes # (cmd line: -E)
+#log_stderror=no	# (cmd line: -E)
+
+
+children=4
 check_via=yes     # (cmd. line: -v)
 dns=on           # (cmd. line: -r)
 rev_dns=yes      # (cmd. line: -R)
-#fork=yes          # (cmd. line: -D)
-fork=no
-children=16
-log_stderror=yes # (cmd line: -E)
-#log_stderror=no	# (cmd line: -E)
 port=5080
 #listen=127.0.0.1
 listen=192.168.99.100
@@ -23,34 +25,46 @@ loop_checks=1
 loadmodule "modules/print/print.so"
 #loadmodule "modules/tm/tm.so"
 
-route{
+route[0]{
+			forward("bat.iptel.org", 5090);
+			break;
+}
+
+route[1]{
+	log("SER: new request reveived\n");
 	if ( t_lookup_request()) {
-		log("SER: transaction found\n");
 		if ( method=="ACK" )	{
-			log("SER: ACK received -> t_release\n");
+			log("SER: ACK for an existing transaction received\n");
 			if (! t_forward("bat.iptel.org", "5090" )) {
 				log("SER: WARNING: bad forward\n");
-			};
+			} else log("SER: t_forward ok\n");
 			if (! t_release()) {
 				log("SER: WARNING: bad t_release\n");
-			};
+			} else log("SER: t_release ok\n");
 		} else {
+			if (method=="INVITE" ) { log("SER: it's an INVITE retranmission\n"); }
+			else if (method=="BYE") log( "SER: it's a BYE retransmission\n")
+			else log("SER: it's a retransmission (neither INVITE nor BYE\n");
 			if (! t_retransmit_reply()) {
 				log("SER: WARNING: bad t_retransmit_reply\n");
-			};
-			log("SER: yet another annoying retranmission\n");
+			} else log("SER: t_retransmit ok\n");
 		};
 		t_unref();
 	} else {
 		log("SER: transaction not found\n");
 		if (method=="ACK") {
 			# no established transaction ... forward ACK just statelessly
+			log("SER: ACK received\n");
 			forward("bat.iptel.org", 5090);
 		} else {
 			# establish transaction
+			log("SER: adding new transaction\n");
+			if (method=="INVITE" ) { log("SER: it's a new INVITE \n"); }
+			else if (method=="BYE") log( "SER: it's a new BYE \n")
+			else log("SER: it is a new transaction (neither INVITE nor BYE)\n");
 			if (! t_add_transaction()){
-				log("ERROR in ser: t_add_transaction\n");
-			};
+				log("SER t_add_transaction failed\n");
+			} else log("SER: t_add_Transactio ok\n");
 			# reply
 			if (method=="CANCEL") {
 				log("SER: new CANCEL\n");
@@ -58,15 +72,15 @@ route{
 					log("SER:ERROR: t_send_reply\n");
 				};
 			} else {
-				log("SER: new transaction\n");
+				log("SER: replying\n");
 				if (! t_send_reply("100", "trying -- your call is important to us")
 					){
 					log("SER: ERROR: t_send_reply (100)\n");
-				};
+				} else log("SER: t_send_reply ok\n");
 			};
 			if (! t_forward("bat.iptel.org", "5090")){
 				log("SER:ERROR: t_forward (..., 5555)\n");
-			};
+			} else log("SER: t_forward ok\n");
 			t_unref();
 		};
 	};

test/xx.cfg

@@ -20,12 +20,8 @@ loop_checks=1
 loadmodule "modules/print/print.so"
 #loadmodule "modules/tm/tm.so"
 
-route[0] {
-	forward(195.37.78.146, 5060);
-	drop;
-}
 
-route[1]{
+route[0]{
 	if ( t_lookup_request()) {
 		if ( method=="ACK" )	{
 			t_release();
@@ -56,3 +52,8 @@ route[1]{
 	};
 		
 }
+
+#route[0] {
+#	forward(195.37.78.146, 5060);
+#	drop;
+#}