Author: bennylp Date: Sat Aug 12 09:56:55 2006 New Revision: 2270 Modified: freeswitch/branches/bennylp/src/mod/endpoints/mod_pjsip/mod_pjsip.c Log: mod_pjsip looks okay, but there is deadlock in switch_channel_hangup() Modified: freeswitch/branches/bennylp/src/mod/endpoints/mod_pjsip/mod_pjsip.c ============================================================================== --- freeswitch/branches/bennylp/src/mod/endpoints/mod_pjsip/mod_pjsip.c (original) +++ freeswitch/branches/bennylp/src/mod/endpoints/mod_pjsip/mod_pjsip.c Sat Aug 12 09:56:55 2006 @@ -42,11 +42,7 @@ #define MOD_PJSIP_CFG "pjsip.conf" #define THIS_FILE pj_thread_get_name(pj_thread_this()) -#if 0 -#define TRACE_(x) PJ_LOG(4,x) -#else -#define TRACE_(x) -#endif +#define TRACE_(x) PJ_LOG(6,x) static switch_memory_pool_t *module_pool = NULL; static pj_caching_pool cp; @@ -195,16 +191,20 @@ void log_func(int level, const char *data, int len) { -#if 1 - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_NOTICE, (char *) data); -#else - static FILE *pjsip_log; - if (pjsip_log == NULL) - pjsip_log = fopen("/tmp/pjsip-fs.log", "w"); + char msg[1024]; + pj_ansi_snprintf(msg, sizeof(msg), "[%s] %s", THIS_FILE, data); + switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_NOTICE, msg); - if (pjsip_log != NULL) { - fwrite(data, len, 1, pjsip_log); - fflush(pjsip_log); +#if PJ_LOG_MAX_LEVEL >= 6 + { + static FILE *pjsip_log; + if (pjsip_log == NULL) + pjsip_log = fopen("/tmp/pjsip-fs.log", "w"); + + if (pjsip_log != NULL) { + fwrite(data, len, 1, pjsip_log); + fflush(pjsip_log); + } } #endif } @@ -406,7 +406,7 @@ assert( profile != NULL ); PJ_LOG(4,(THIS_FILE, "Hangup call %s dialog=%s", tech_pvt->call_id, - tech_pvt->sip_invite->dlg->obj_name)); + (tech_pvt->sip_invite ? tech_pvt->sip_invite->dlg->obj_name : "none"))); /* remove call from hash */ switch_core_hash_delete( profile->call_hash, tech_pvt->call_id ); @@ -416,18 +416,19 @@ stop_rtp( tech_pvt ); - //PJ_TODO(should_we_clear_dlg_data_here); + /* Hangup PJSIP call */ + if (tech_pvt->sip_invite && tech_pvt->sip_invite->state < PJSIP_INV_STATE_DISCONNECTED) { + status = pjsip_inv_end_session( tech_pvt->sip_invite, 200, NULL, &txdata ); + if( status == PJ_SUCCESS ) { + add_server_header(txdata); + status = pjsip_inv_send_msg( tech_pvt->sip_invite, txdata ); + } - status = pjsip_inv_end_session( tech_pvt->sip_invite, 200, NULL, &txdata ); - if( status == PJ_SUCCESS ) { - add_server_header(txdata); - status = pjsip_inv_send_msg( tech_pvt->sip_invite, txdata ); + if (status != PJ_SUCCESS) { + perror_(tech_pvt->sip_invite->dlg->obj_name, "Unable to hangup", status); + } } - if (status != PJ_SUCCESS) { - perror_(tech_pvt->sip_invite->dlg->obj_name, "Unable to hangup", status); - } - if (switch_test_flag( tech_pvt, TFLAG_USING_CODEC ) ) { switch_core_codec_destroy( &tech_pvt->read_codec ); switch_core_codec_destroy( &tech_pvt->write_codec ); @@ -442,6 +443,8 @@ struct private_object *tech_pvt; switch_channel_t *channel; + TRACE_((THIS_FILE, "ENTER pjsip_on_loopback")); + channel = switch_core_session_get_channel( session ); assert( channel != NULL ); @@ -450,6 +453,7 @@ /* do nothing */ + TRACE_((THIS_FILE, "LEAVE pjsip_on_loopback")); return SWITCH_STATUS_SUCCESS; } @@ -458,6 +462,8 @@ struct private_object *tech_pvt; switch_channel_t *channel; + TRACE_((THIS_FILE, "ENTER pjsip_on_transmit")); + assert( session != NULL ); channel = switch_core_session_get_channel( session ); @@ -468,6 +474,7 @@ /* do nothing */ + TRACE_((THIS_FILE, "LEAVE pjsip_on_transmit")); return SWITCH_STATUS_SUCCESS; } @@ -763,6 +770,7 @@ switch_clear_flag_locked(tech_pvt, TFLAG_READING); if (switch_test_flag(tech_pvt, TFLAG_BYE)) { + TRACE_((THIS_FILE, "switch_channel_hangup(%x) called by pjsip_read_frame()", channel)); switch_channel_hangup(channel, SWITCH_CAUSE_NORMAL_CLEARING); return SWITCH_STATUS_FALSE; } @@ -793,6 +801,7 @@ } if (switch_test_flag(tech_pvt, TFLAG_BYE)) { + TRACE_((THIS_FILE, "switch_channel_hangup(%x) called by pjsip_write_frame()", channel)); switch_channel_hangup(channel, SWITCH_CAUSE_NORMAL_CLEARING); return SWITCH_STATUS_FALSE; } @@ -1146,7 +1155,7 @@ } /* Add Server header */ - add_server_header(tdata); + add_server_header(tdata); /* TODO: it would be nice if we could add SDP body here (dunno how) */ //PJ_TODO(ADD_SDP_TO_OPTIONS_RESPONSE); @@ -1170,8 +1179,6 @@ { pj_str_t reason; - PJ_LOG(4,(THIS_FILE,"%s: received new request", __FUNCTION__ )); - switch( rxdata->msg_info.msg->line.req.method.id ) { case PJSIP_INVITE_METHOD: on_incoming_call( rxdata ); @@ -1241,7 +1248,10 @@ switch_core_session_t *session; switch_channel_t *channel; + /* evt may be NULL if invite is terminated by pjsip_inv_terminate() assert ( evt != NULL); + */ + assert ( inv != NULL ); if (!(tech_pvt = inv->mod_data[globals.mod_app.id])) { @@ -1271,28 +1281,35 @@ switch( inv->state ) { case PJSIP_INV_STATE_DISCONNECTED: + /* Remove association between PJSIP call and channel, to prevent + * other channels from re-entering PJSIP for the context of this INVITE + * (which is guaranteed to cause deadlock!) + */ + pjsip_dlg_inc_lock(inv->dlg); + + switch_mutex_lock(tech_pvt->flag_mutex); inv->mod_data[globals.mod_app.id] = NULL; + tech_pvt->sip_invite = NULL; + tech_pvt->sip_dialog = NULL; + switch_mutex_unlock(tech_pvt->flag_mutex); + PJ_LOG(4,(THIS_FILE, "* Call %s (%s) has been disconnected", tech_pvt->call_id, switch_channel_get_name( channel ) )); if( !switch_test_flag( tech_pvt, TFLAG_BYE ) ) { switch_call_cause_t cause; - switch( evt->body.rx_msg.rdata->msg_info.msg->line.status.code ) + switch( inv->cause ) { default: - /* bennylp: we can get the INVITE disconnect cause from inv->cause. - * and the reason in inv->cause_text. - * But how do we map it to switch cause? - */ - //PJ_TODO(MAP_SIP_STATUS_CODE_TO_SWITCH_CAUSE_CODE); cause = SWITCH_CAUSE_NORMAL_CLEARING; } - TRACE_((THIS_FILE, "LOOK HERE!!! Entering switch_channel_hangup for dialog %s", - inv->dlg->obj_name)); + TRACE_((THIS_FILE, "LOOK HERE!!! Entering switch_channel_hangup(%x) for dialog %s", + channel, inv->dlg->obj_name)); switch_channel_hangup( channel, cause ); TRACE_((THIS_FILE, "LOOK HERE!!! Leaving switch_channel_hangup")); } + pjsip_dlg_dec_lock(inv->dlg); break; case PJSIP_INV_STATE_CONFIRMED: PJ_LOG(4,(THIS_FILE, "* Call %s (%s) has been connected", tech_pvt->call_id, @@ -1392,7 +1409,7 @@ } if( status != PJ_SUCCESS ) { - char tmp[1024]; + char tmp[PJ_ERR_MSG_SIZE]; pj_strerror( status, tmp, sizeof(tmp) ); PJ_LOG(1,(THIS_FILE, "SDP negotiation failed for call %s, reason: %s", tech_pvt->call_id, tmp )); switch_channel_hangup( channel, SWITCH_CAUSE_DESTINATION_OUT_OF_ORDER ); @@ -1775,7 +1792,7 @@ ( switch_test_flag( tech_pvt, TFLAG_READING ) || switch_test_flag( tech_pvt, TFLAG_WRITING ) ) ) { - switch_yield( 1000 ); + switch_yield( 10 ); loop++; } @@ -2124,10 +2141,15 @@ */ status = pjsip_udp_transport_start( globals.sip_endpt, &profile->sip_addr, NULL, 1, &transport ); if ( status != PJ_SUCCESS ) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to create UDP transport: %s [%s:%d]\n", profile->name, profile->sip_ip, profile->sip_port ); + PJ_LOG( 1, (THIS_FILE, "Failed to create UDP transport: %s [%s:%d]", + profile->name, profile->sip_ip, profile->sip_port )); return SWITCH_STATUS_TERM; } + PJ_LOG(3,(THIS_FILE, "UDP transport created, listening on %.*s:%d", + (int)transport->local_name.host.slen, transport->local_name.host.ptr, + transport->local_name.port)); + /* add transports name to hash */ switch_core_hash_insert( globals.transport_hash, transport->obj_name, profile ); } @@ -2212,8 +2234,6 @@ return SWITCH_STATUS_TERM; } - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_INFO, "Monitor thread running\n" ); - globals.running = 1; /* Create PJSIP from worker threads */ @@ -2225,9 +2245,11 @@ } } + switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_INFO, "Monitor thread running\n" ); + /* Another worker */ while ( globals.running > 0 ) { - pj_time_val timeout = { 1, 0 }; + pj_time_val timeout = { 0, 100 }; TRACE_((THIS_FILE, "ENTER pjsip_endpt_handle_events")); pjsip_endpt_handle_events( globals.sip_endpt, &timeout ); TRACE_((THIS_FILE, "LEAVE pjsip_endpt_handle_events"));