Author: bennylp Date: Fri Aug 11 14:24:06 2006 New Revision: 2261 Removed: freeswitch/branches/bennylp/src/mod/endpoints/mod_pjsip/pjsdp/ Modified: freeswitch/branches/bennylp/conf/freeswitch.xml freeswitch/branches/bennylp/src/mod/endpoints/mod_pjsip/Makefile freeswitch/branches/bennylp/src/mod/endpoints/mod_pjsip/mod_pjsip.c freeswitch/branches/bennylp/src/mod/endpoints/mod_pjsip/mod_pjsip_sdp.c Log: Bug hunting season in mod_pjsip. Looks a bit better, but who knows... Modified: freeswitch/branches/bennylp/conf/freeswitch.xml ============================================================================== --- freeswitch/branches/bennylp/conf/freeswitch.xml (original) +++ freeswitch/branches/bennylp/conf/freeswitch.xml Fri Aug 11 14:24:06 2006 @@ -27,7 +27,9 @@ <!-- <load module="mod_ldap"/> --> <!-- Endpoints --> - <load module="mod_exosip"/> + <!-- load module="mod_exosip"/> --> + <load module="mod_pjsip"/> + <!-- load module="mod_pjsip_sdp"/> --> <!--<load module="mod_iax"/>--> <load module="mod_portaudio"/> <!-- <load module="mod_woomera"/> --> @@ -82,6 +84,17 @@ </settings> </configuration> + <configuration name="pjsip.conf" description="PJSIP Configuration"> + <profile name="default"> + <!-- <param name="ip" value="1.2.3.4"/> --> + <!-- note: only udp transport supported for now! --> + <!-- <param name="transport" value="udp,tcp,tls"/> --> + <param name="port" value="5060"/> + <param name="max-calls" value="10"/> + <param name="dialplan" value="XML"/> + </profile> + </configuration> + <configuration name="iax.conf" description="IAX Configuration"> <settings> <param name="debug" value="0"/> @@ -369,8 +382,8 @@ <!-- Enter an existing conference --> <extension name="1000"> - <condition field="destination_number" expression="^1000$"> - <action application="conference" data="freeswitch"/> + <condition field="destination_number" expression=".*"> + <action application="playback" data="/usr/local/freeswitch/cluecon1.wav"/> </condition> </extension> Modified: freeswitch/branches/bennylp/src/mod/endpoints/mod_pjsip/Makefile ============================================================================== --- freeswitch/branches/bennylp/src/mod/endpoints/mod_pjsip/Makefile (original) +++ freeswitch/branches/bennylp/src/mod/endpoints/mod_pjsip/Makefile Fri Aug 11 14:24:06 2006 @@ -6,8 +6,8 @@ LINKER=$(CC) endif -PJ_PROJECT=pjproject-0.5.6 -PJ_DIR=$(BASE)/libs/$(PJ_PROJECT) +PJ_PROJECT=/root/project/pjproject +PJ_DIR=/root/project/pjproject ifeq ($(MAKECMDGOALS),build) CC_DEF=-D @@ -17,29 +17,25 @@ include $(PJ_DIR)/build/os-$(OS_NAME).mak CFLAGS += -I$(PJ_DIR)/pjlib/include -I$(PJ_DIR)/pjlib-util/include -I$(PJ_DIR)/pjsip/include -CFLAGS += -I$(PJ_DIR)/pjmedia/include -I./pjsdp/pjsdp/include +CFLAGS += -I$(PJ_DIR)/pjmedia/include CFLAGS += $(OS_CFLAGS) $(M_CFLAGS) -LDFLAGS += -L$(PJ_DIR)/pjlib/lib -L$(PJ_DIR)/pjlib-util/lib -L$(PJ_DIR)/pjsip/lib -L./pjsdp/pjsdp/lib +LDFLAGS += -L$(PJ_DIR)/pjlib/lib -L$(PJ_DIR)/pjlib-util/lib -L$(PJ_DIR)/pjsip/lib -L$(PJ_DIR)/pjmedia/lib LDFLAGS += -lpjsip-$(TARGET_NAME) -lpjsip-ua-$(TARGET_NAME) -lpjsip-simple-$(TARGET_NAME) LDFLAGS += -lpjsdp-$(TARGET_NAME) -lpjlib-util-$(TARGET_NAME) -lpj-$(TARGET_NAME) endif OBJS=mod_pjsip_sdp.o -.PHONY: pjsdp +.PHONY: all: depends $(MAKE) build -build: pjsdp $(OBJS) $(MODNAME).$(DYNAMIC_LIB_EXTEN) +build: $(OBJS) $(MODNAME).$(DYNAMIC_LIB_EXTEN) -pjsdp: - $(MAKE) CFLAGS="$(filter-out -Werror,$(CFLAGS)) -fPIC" -C pjsdp - depends: - MAKE=$(MAKE) $(BASE)/build/buildlib.sh $(BASE) $(PJ_PROJECT).tar.gz --prefix=$(PREFIX) - (cd pjsdp; ./configure) +# MAKE=$(MAKE) $(BASE)/build/buildlib.sh $(BASE) $(PJ_PROJECT).tar.gz --prefix=$(PREFIX) %.o: %.c $(CC) -fPIC $(CFLAGS) -c -o $@ $< @@ -50,7 +46,6 @@ clean: rm -fr *.$(DYNAMIC_LIB_EXTEN) *.o *~ - $(MAKE) -C pjsdp realclean install: cp -f $(MODNAME).$(DYNAMIC_LIB_EXTEN) $(DESTDIR)$(PREFIX)/mod 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 Fri Aug 11 14:24:06 2006 @@ -29,7 +29,7 @@ #define HAVE_APR #include <switch.h> #include <pjsip.h> -#include <pjsdp.h> +#include <pjmedia.h> #include <pjsip_ua.h> #include <pjsip_simple.h> #include <pjlib-util.h> @@ -40,11 +40,19 @@ static const char modname[] = "mod_pjsip"; #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 + static switch_memory_pool_t *module_pool = NULL; static pj_caching_pool cp; static pjsip_inv_callback invite_cb; static pj_pool_t *pjsip_pool; +static pj_str_t FREESWITCH_SERVER; #define DEFAULT_PORT 5060 @@ -182,6 +190,31 @@ /*.application_interface */ NULL }; + +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"); + + if (pjsip_log != NULL) { + fwrite(data, len, 1, pjsip_log); + fflush(pjsip_log); + } +#endif +} + +static void perror_(const char *sender, const char *title, pj_status_t status) +{ + char errmsg[PJ_ERR_MSG_SIZE]; + + pj_strerror(status, errmsg, sizeof(errmsg)); + PJ_LOG(1,(sender, "ERROR: %s: %s", title, errmsg)); +} + /* */ static int pjsip_strncpy( char *dst, const pj_str_t *src, int maxlen ) { @@ -193,6 +226,21 @@ return len; } + +static void add_server_header(pjsip_tx_data *tdata) +{ + const pj_str_t SERVER = { "Server", 6}; + pjsip_hdr *h; + + h = (pjsip_hdr*) pjsip_generic_string_hdr_create(tdata->pool, + &SERVER, + &FREESWITCH_SERVER); + pjsip_msg_add_hdr(tdata->msg, h); + +} + + + static switch_status_t pjsip_on_init(switch_core_session_t *session) { struct pjsip_profile *profile; @@ -200,6 +248,7 @@ switch_channel_t *channel; pj_status_t status; + channel = switch_core_session_get_channel( session ); assert( channel != NULL ); @@ -212,11 +261,13 @@ /* register switch thread to pjsip core */ status = pj_thread_register( NULL, tech_pvt->thread_desc, &tech_pvt->thread ); if( status != PJ_SUCCESS ) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Could not register switch session thread to pjlib\n" ); + perror_(THIS_FILE, "Could not register switch session thread to pjlib", status); switch_core_session_destroy( &session ); return SWITCH_STATUS_GENERR; } + TRACE_((THIS_FILE, "ENTER pjsip_on_init")); + if( switch_channel_test_flag( channel, CF_OUTBOUND ) ) { pjsip_tx_data *txdata = NULL; @@ -226,18 +277,21 @@ switch_copy_string( tmp, tech_pvt->caller_profile->destination_number, sizeof( tmp ) ); if( !(destination = strchr( tmp, '/' )) ) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Malformed URL!\n" ); + PJ_LOG(1,(THIS_FILE, "Malformed URL!")); switch_core_session_destroy( &session ); + TRACE_((THIS_FILE, "LEAVE pjsip_on_init")); return SWITCH_STATUS_GENERR; } *destination++ = '\0'; pj_ansi_sprintf( tmp, "<sip:%s:%d>", destination, 5060 ); - pj_cstr( &dst, tmp ); + dst = pj_str( tmp ); tech_pvt->sip_ua = pjsip_ua_instance(); - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "Dst: %s, Local: %s %s\n", tmp, tech_pvt->profile->local_uri.ptr, tech_pvt->profile->local_contact.ptr ); + PJ_LOG(5,(THIS_FILE, "Dst: %s, Local: %s %s", tmp, + tech_pvt->profile->local_uri.ptr, + tech_pvt->profile->local_contact.ptr)); /* create new UAC dialog */ status = pjsip_dlg_create_uac( tech_pvt->sip_ua, @@ -248,20 +302,23 @@ &tech_pvt->sip_dialog ); if ( status != PJ_SUCCESS ) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to create new UAC dialog for call\n" ); + perror_(THIS_FILE,"Failed to create new UAC dialog for call", status); switch_core_session_destroy( &session ); + TRACE_((THIS_FILE, "LEAVE pjsip_on_init")); return SWITCH_STATUS_GENERR; } /* create SDP */ create_sdp( tech_pvt->sip_dialog->pool, tech_pvt, &sdp, NULL ); - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "Initial SDP created\n" ); + PJ_LOG(5,(THIS_FILE, "Initial SDP created")); /* create INVITE session */ - if ((status = pjsip_inv_create_uac( tech_pvt->sip_dialog, sdp, 0, &tech_pvt->sip_invite ) != PJ_SUCCESS )) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to create new INVITE session for call %s\n" ); + status = pjsip_inv_create_uac( tech_pvt->sip_dialog, sdp, 0, &tech_pvt->sip_invite ); + if (status != PJ_SUCCESS ) { + perror_(tech_pvt->sip_dialog->obj_name, "Failed to create new INVITE session", status); pjsip_dlg_terminate( tech_pvt->sip_dialog ); + TRACE_((THIS_FILE, "LEAVE pjsip_on_init")); return SWITCH_STATUS_GENERR; } @@ -269,52 +326,38 @@ /* attach private object to pjsip session data */ tech_pvt->sip_invite->mod_data[globals.mod_app.id] = tech_pvt; - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "Invite UAC created\n" ); - /* create invite request */ status = pjsip_inv_invite( tech_pvt->sip_invite, &txdata ); if ( status != PJ_SUCCESS ) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to create initial INVITE request for call %s\n" ); - pjsip_dlg_terminate( tech_pvt->sip_dialog ); + perror_( tech_pvt->sip_dialog->obj_name, "Failed to create initial INVITE request", status ); + pjsip_inv_terminate(tech_pvt->sip_invite, 500, PJ_FALSE); + TRACE_((THIS_FILE, "LEAVE pjsip_on_init")); return SWITCH_STATUS_GENERR; } - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "Initial INVITE created\n" ); + /* set call id (now, before invite is sent, so that when callback is called, + * tech_pvt has the correct call_id) + */ + strncpy( tech_pvt->call_id, tech_pvt->sip_invite->dlg->call_id->id.ptr, + PJ_MAX_STRLEN( tech_pvt->call_id, tech_pvt->sip_invite->dlg->call_id->id ) ); /* send request */ + add_server_header(txdata); status = pjsip_inv_send_msg( tech_pvt->sip_invite, txdata ); if ( status != PJ_SUCCESS ) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to send INVITE request for call %s\n" ); - pjsip_dlg_terminate( tech_pvt->sip_dialog ); + perror_(tech_pvt->sip_dialog->obj_name, "Failed to send INVITE request for call", status); + pjsip_inv_terminate(tech_pvt->sip_invite, 500, PJ_FALSE); + TRACE_((THIS_FILE, "LEAVE pjsip_on_init")); return SWITCH_STATUS_GENERR; } - - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "INVITE sent\n" ); - - /* set call id */ - strncpy( tech_pvt->call_id, tech_pvt->sip_invite->dlg->call_id->id.ptr, PJ_MAX_STRLEN( tech_pvt->call_id, tech_pvt->sip_invite->dlg->call_id->id ) ); - } else { - pjsip_tx_data *txdata; - - /* Send 180 Ring */ - status = pjsip_inv_answer( tech_pvt->sip_invite, 180, NULL, NULL, &txdata ); - if( status != PJ_SUCCESS ) { - status = pjsip_inv_answer( tech_pvt->sip_invite, PJSIP_SC_NOT_ACCEPTABLE, NULL, NULL, &txdata ); - - if( status == PJ_SUCCESS ) - pjsip_inv_send_msg( tech_pvt->sip_invite, txdata ); - else - pjsip_inv_terminate( tech_pvt->sip_invite, 500, PJ_FALSE ); - - switch_core_session_destroy( &session ); - return SWITCH_STATUS_GENERR; - } - pjsip_inv_send_msg( tech_pvt->sip_invite, txdata ); } + + /* add call to hash */ switch_core_hash_insert( profile->call_hash, tech_pvt->call_id, tech_pvt ); switch_channel_set_state( channel, CS_RING ); + TRACE_((THIS_FILE, "LEAVE pjsip_on_init")); return SWITCH_STATUS_SUCCESS; } @@ -323,6 +366,8 @@ struct private_object *tech_pvt; switch_channel_t *channel; + TRACE_((THIS_FILE, "ENTER pjsip_on_ring")); + assert( session != NULL ); channel = switch_core_session_get_channel( session ); @@ -331,8 +376,9 @@ tech_pvt = switch_core_session_get_private( session ); assert( tech_pvt != NULL ); - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_INFO, "RING %s\n", switch_channel_get_name( channel ) ); + PJ_LOG(4,(THIS_FILE, "RING %s", switch_channel_get_name( channel ))); + TRACE_((THIS_FILE, "LEAVE pjsip_on_ring")); return SWITCH_STATUS_SUCCESS; } @@ -344,6 +390,8 @@ pj_status_t status; pjsip_tx_data *txdata; + TRACE_((THIS_FILE, "ENTER pjsip_on_hangup")); + assert( session != NULL ); channel = switch_core_session_get_channel( session ); @@ -355,7 +403,8 @@ profile = tech_pvt->profile; assert( profile != NULL ); - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "Hangup call %s\n", tech_pvt->call_id ); + PJ_LOG(4,(THIS_FILE, "Hangup call %s dialog=%s", tech_pvt->call_id, + tech_pvt->sip_invite->dlg->obj_name)); /* remove call from hash */ switch_core_hash_delete( profile->call_hash, tech_pvt->call_id ); @@ -365,20 +414,24 @@ stop_rtp( tech_pvt ); - if( tech_pvt->sip_invite->state < PJSIP_INV_STATE_CONFIRMED ) { - pjsip_inv_terminate( tech_pvt->sip_invite, 500, PJ_TRUE ); - } else { - status = pjsip_inv_end_session( tech_pvt->sip_invite, 200, NULL, &txdata ); - if( status != PJ_SUCCESS ) - pjsip_inv_terminate( tech_pvt->sip_invite, 500, PJ_TRUE ); - else - pjsip_inv_send_msg( tech_pvt->sip_invite, txdata ); + //PJ_TODO(should_we_clear_dlg_data_here); + + 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 ( switch_test_flag( tech_pvt, TFLAG_USING_CODEC ) ) { + 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 ); } + + TRACE_((THIS_FILE, "LEAVE pjsip_on_hangup")); return SWITCH_STATUS_SUCCESS; } @@ -422,6 +475,8 @@ struct private_object *tech_pvt; switch_channel_t *channel; + TRACE_((THIS_FILE, "ENTER pjsip_answer_channel")); + assert( session != NULL ); channel = switch_core_session_get_channel( session ); @@ -430,7 +485,7 @@ tech_pvt = switch_core_session_get_private( session ); assert( tech_pvt != NULL ); - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "* Answering call %s\n", tech_pvt->call_id ); + PJ_LOG(4,(THIS_FILE, "* Answering call %s", tech_pvt->call_id)); if( !switch_test_flag( tech_pvt, TFLAG_ANSWERED ) && !switch_channel_test_flag( channel, CF_OUTBOUND ) ) @@ -440,24 +495,33 @@ assert( tech_pvt->sip_invite != NULL ); - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "* Sending 200 on INVITE to %s (%s)\n", tech_pvt->call_id, switch_channel_get_name( channel ) ); + PJ_LOG(4,(THIS_FILE, "* Sending 200 on INVITE to %s (%s)", + tech_pvt->call_id, switch_channel_get_name( channel ) )); /* create SIP 200 with SDP */ status = pjsip_inv_answer( tech_pvt->sip_invite, 200, NULL, NULL, &txdata ); if( status != PJ_SUCCESS ) { + perror_(tech_pvt->sip_invite->dlg->obj_name, "pjsip_inv_answer error", status); + pjsip_inv_terminate( tech_pvt->sip_invite, 500, PJ_TRUE ); switch_core_session_destroy( &session ); + TRACE_((THIS_FILE, "LEAVE pjsip_answer_channel")); return SWITCH_STATUS_GENERR; } + 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, "pjsip_inv_send_msg(200) error", status); + pjsip_inv_terminate( tech_pvt->sip_invite, 500, PJ_TRUE ); switch_core_session_destroy( &session ); + TRACE_((THIS_FILE, "LEAVE pjsip_answer_channel")); return SWITCH_STATUS_GENERR; } } switch_set_flag_locked( tech_pvt, TFLAG_ANSWERED ); + TRACE_((THIS_FILE, "LEAVE pjsip_answer_channel")); return SWITCH_STATUS_SUCCESS; } @@ -467,6 +531,8 @@ struct private_object *tech_pvt; switch_channel_t *channel; + TRACE_((THIS_FILE, "ENTER pjsip_kill_channel")); + assert( session != NULL ); channel = switch_core_session_get_channel( session ); @@ -475,12 +541,17 @@ tech_pvt = switch_core_session_get_private( session ); assert( tech_pvt != NULL ); - switch_clear_flag_locked( tech_pvt, TFLAG_IO ); - switch_set_flag_locked( tech_pvt, TFLAG_BYE ); - - if( tech_pvt->rtp_session ) { - switch_rtp_kill_socket( tech_pvt->rtp_session ); + if (sig == SWITCH_SIG_KILL) { + switch_mutex_lock(tech_pvt->flag_mutex); + switch_clear_flag( tech_pvt, TFLAG_IO ); + switch_set_flag( tech_pvt, TFLAG_BYE ); + if( tech_pvt->rtp_session ) { + switch_rtp_kill_socket( tech_pvt->rtp_session ); + } + switch_mutex_unlock(tech_pvt->flag_mutex); } + + TRACE_((THIS_FILE, "LEAVE pjsip_kill_channel")); return SWITCH_STATUS_SUCCESS; } @@ -502,8 +573,10 @@ /* create new call */ -static switch_status_t pjsip_outgoing_channel(switch_core_session_t *session, switch_caller_profile_t *outbound_profile, - switch_core_session_t **new_session, switch_memory_pool_t *pool) +static switch_status_t pjsip_outgoing_channel(switch_core_session_t *session, + switch_caller_profile_t *outbound_profile, + switch_core_session_t **new_session, + switch_memory_pool_t *pool) { struct private_object *tech_pvt = NULL; switch_channel_t *channel = NULL; @@ -524,24 +597,32 @@ return SWITCH_STATUS_GENERR; } - if( !( profile = (struct pjsip_profile *) switch_core_hash_find( globals.profiles_hash, profile_name ) )) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Unknown profile: %s\n", profile_name ); + profile = (struct pjsip_profile *) switch_core_hash_find( globals.profiles_hash, profile_name ); + if( !profile) { + switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, + "Unknown profile: %s\n", profile_name ); return SWITCH_STATUS_GENERR; } - if ( !( *new_session = switch_core_session_request( &pjsip_endpoint_interface, pool ) ) ) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to create new session for call\n" ); + *new_session = switch_core_session_request( &pjsip_endpoint_interface, pool ); + if ( !(*new_session) ) { + switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, + "Failed to create new session for call\n" ); return SWITCH_STATUS_GENERR; } switch_core_session_add_stream( *new_session, NULL ); /* create new call */ - if (!(tech_pvt = (struct private_object *) switch_core_session_alloc(*new_session, sizeof(struct private_object)))) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to create new private object for call\n" ); + tech_pvt = (struct private_object *) + switch_core_session_alloc(*new_session, sizeof(struct private_object)); + if (!tech_pvt) { + switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, + "Failed to create new private object for call\n" ); goto err; } tech_pvt->session = *new_session; - switch_mutex_init(&tech_pvt->flag_mutex, SWITCH_MUTEX_NESTED, switch_core_session_get_pool(*new_session)); + switch_mutex_init(&tech_pvt->flag_mutex, SWITCH_MUTEX_NESTED, + switch_core_session_get_pool(*new_session)); tech_pvt->profile = profile; switch_core_session_set_private( *new_session, tech_pvt ); @@ -552,8 +633,10 @@ switch_channel_set_name( channel, tmp ); /* get list of all available codecs */ - tech_pvt->num_codecs = switch_loadable_module_get_codecs( switch_core_session_get_pool(tech_pvt->session), tech_pvt->codecs, - sizeof(tech_pvt->codecs) / sizeof(tech_pvt->codecs[0]) ); + tech_pvt->num_codecs = + switch_loadable_module_get_codecs( switch_core_session_get_pool(tech_pvt->session), + tech_pvt->codecs, + sizeof(tech_pvt->codecs) / sizeof(tech_pvt->codecs[0]) ); caller_profile = switch_caller_profile_clone( *new_session, outbound_profile ); switch_channel_set_caller_profile( channel, caller_profile ); @@ -571,8 +654,9 @@ } -static switch_status_t pjsip_read_frame(switch_core_session_t *session, switch_frame_t **frame, int timeout, - switch_io_flag_t flags, int stream_id) +static switch_status_t pjsip_read_frame(switch_core_session_t *session, + switch_frame_t **frame, int timeout, + switch_io_flag_t flags, int stream_id) { struct private_object *tech_pvt = NULL; size_t bytes = 0, samples = 0, frames = 0, ms = 0; @@ -609,7 +693,10 @@ tech_pvt->read_frame.datalen = 0; - while (!switch_test_flag(tech_pvt, TFLAG_BYE) && switch_test_flag(tech_pvt, TFLAG_IO) && tech_pvt->read_frame.datalen == 0) { + while (!switch_test_flag(tech_pvt, TFLAG_BYE) && + switch_test_flag(tech_pvt, TFLAG_IO) && + tech_pvt->read_frame.datalen == 0) + { now = switch_time_now(); tech_pvt->read_frame.flags = 0; @@ -651,7 +738,6 @@ switch_channel_queue_dtmf(channel, dtmf); } - if (tech_pvt->read_frame.datalen > 0) { tech_pvt->last_read = switch_time_now(); if (tech_pvt->read_codec.implementation->encoded_bytes_per_frame) { @@ -685,8 +771,9 @@ } -static switch_status_t pjsip_write_frame(switch_core_session_t *session, switch_frame_t *frame, int timeout, - switch_io_flag_t flags, int stream_id) +static switch_status_t pjsip_write_frame(switch_core_session_t *session, + switch_frame_t *frame, int timeout, + switch_io_flag_t flags, int stream_id) { struct private_object *tech_pvt; switch_channel_t *channel = NULL; @@ -711,7 +798,6 @@ switch_set_flag_locked(tech_pvt, TFLAG_WRITING); - if (tech_pvt->read_codec.implementation->encoded_bytes_per_frame) { bytes = tech_pvt->read_codec.implementation->encoded_bytes_per_frame; frames = ((int) frame->datalen / bytes); @@ -730,6 +816,7 @@ /* END: freeswitch callbacks */ + /* BEGIN: pjsip callbacks */ /* @@ -741,13 +828,16 @@ struct pjsip_profile *profile; pj_status_t status; + TRACE_((THIS_FILE, "ENTER on_incoming_call")); + /* How to map rxdata / transport -> profile? */ - if( !( profile = switch_core_hash_find( globals.transport_hash, rxdata->tp_info.transport->obj_name )) ) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Profile not found\n" ); - return; + profile = switch_core_hash_find( globals.transport_hash, rxdata->tp_info.transport->obj_name ); + if( !profile ) { + PJ_LOG(1,(THIS_FILE,"Profile not found" )); + goto on_return; } - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "*** New incoming call for profile %s\n", profile->name ); + PJ_LOG(4,(THIS_FILE, "*** New incoming call for profile %s", profile->name )); /* check call limit */ if( profile->max_calls && ( profile->calls + 1 ) > profile->max_calls ) { @@ -756,12 +846,10 @@ 500, &reason, NULL, NULL); - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Too many calls (profile: %s)\n", profile->name ); - return; + PJ_LOG(1,(THIS_FILE, "Too many calls (profile: %s)", profile->name )); + goto on_return; } - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_INFO, "PJSIP process id %lu, thread name %s\n", pj_getpid(), pj_thread_get_name( pj_thread_this() ) ); - if ((session = switch_core_session_request( &pjsip_endpoint_interface, NULL ))) { struct private_object *tech_pvt; switch_channel_t *channel; @@ -775,30 +863,26 @@ /* allocate new session */ switch_core_session_add_stream( session, NULL ); - if (!(tech_pvt = (struct private_object *) switch_core_session_alloc( session, sizeof(struct private_object) ))) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to create new channel for inbound call\n" ); + tech_pvt = (struct private_object *) + switch_core_session_alloc( session, sizeof(struct private_object) ); + if (!tech_pvt) { + perror_(THIS_FILE, "Failed to create new channel for inbound call", -1); switch_core_session_destroy( &session ); - return; + goto on_return; } - switch_core_session_set_private( session, tech_pvt ); tech_pvt->session = session; + switch_core_session_set_private( session, tech_pvt ); - switch_mutex_init(&tech_pvt->flag_mutex, SWITCH_MUTEX_NESTED, switch_core_session_get_pool(session)); + switch_mutex_init(&tech_pvt->flag_mutex, SWITCH_MUTEX_NESTED, + switch_core_session_get_pool(session)); + switch_mutex_lock(tech_pvt->flag_mutex); + /* need the invite data in pjsip_on_init */ tech_pvt->sip_ua = pjsip_ua_instance(); tech_pvt->profile = profile; - /* give the new session a name */ - pj_strdup_with_null( pjsip_pool, &tmp, &((pjsip_sip_uri *)rxdata->msg_info.from->uri)->host ); - snprintf( name, sizeof(name), "pjsip/%s/%s-%04x", profile->name, tmp.ptr, rand() & 0xffff ); - switch_channel_set_name( channel, name ); - - switch_channel_clear_flag( channel, CF_OUTBOUND ); - - - /* create UAS dialog */ status = pjsip_dlg_create_uas( tech_pvt->sip_ua, rxdata, NULL, &dialog ); if( status != PJ_SUCCESS ) { @@ -806,14 +890,30 @@ pjsip_endpt_respond_stateless( globals.sip_endpt, rxdata, 500, &reason, NULL, NULL); - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to create new pjsip dialog for inbound call\n" ); + perror_(THIS_FILE,"Failed to create new pjsip dialog for inbound call", status); + switch_mutex_unlock(tech_pvt->flag_mutex); switch_core_session_destroy( &session ); - return; + goto on_return; } + /* give the new session a name */ + pj_strdup_with_null( dialog->pool, &tmp, + &((pjsip_sip_uri *)rxdata->msg_info.from->uri)->host ); + snprintf( name, sizeof(name), "pjsip/%s/%s-%04x", profile->name, tmp.ptr, rand() & 0xffff ); + switch_channel_set_name( channel, name ); + + switch_channel_clear_flag( channel, CF_OUTBOUND ); + + /* lock dialog, to prevent callbacks to be called while we're setting + * up the dialog + */ + pjsip_dlg_inc_lock(dialog); + /* load codecs */ - tech_pvt->num_codecs = switch_loadable_module_get_codecs( switch_core_session_get_pool(tech_pvt->session), tech_pvt->codecs, - sizeof(tech_pvt->codecs) / sizeof(tech_pvt->codecs[0]) ); + tech_pvt->num_codecs = + switch_loadable_module_get_codecs( switch_core_session_get_pool(tech_pvt->session), + tech_pvt->codecs, + sizeof(tech_pvt->codecs) / sizeof(tech_pvt->codecs[0]) ); /* Create our initial sdp */ create_sdp( dialog->pool, tech_pvt, &sdp, NULL ); @@ -821,35 +921,68 @@ /* Create UAS invite session */ - if ((status = pjsip_inv_create_uas( dialog, rxdata, sdp, 0, &tech_pvt->sip_invite ) != PJ_SUCCESS )) { - pjsip_dlg_create_response( dialog, rxdata, 500, NULL, &txdata ); - pjsip_dlg_send_response( dialog, pjsip_rdata_get_tsx( rxdata ), txdata ); + status = pjsip_inv_create_uas( dialog, rxdata, sdp, 0, &tech_pvt->sip_invite ); + if (status != PJ_SUCCESS) { + pjsip_hdr hdr_list; + pjsip_warning_hdr *w; - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to create new pjsip dialog for inbound call\n" ); + perror_(THIS_FILE, "Failed to create new pjsip dialog for inbound call", status ); + + /* Send 500, adding Warning header to explain why it went wrong */ + w = pjsip_warning_hdr_create_from_status(dialog->pool, + pjsip_endpt_name(globals.sip_endpt), + status); + pj_list_init(&hdr_list); + pj_list_push_back(&hdr_list, w); + + pjsip_dlg_respond(dialog, rxdata, 500, NULL, &hdr_list, NULL); + switch_core_session_destroy( &session ); - return; + + /* unlock (and probably destroy) dialog */ + pjsip_dlg_dec_lock(dialog); + switch_mutex_unlock(tech_pvt->flag_mutex); + goto on_return; } - + tech_pvt->sip_invite->mod_data[globals.mod_app.id] = tech_pvt; tech_pvt->profile = profile; - pj_strdup_with_null( pjsip_pool, &username, &((pjsip_sip_uri *)rxdata->msg_info.from->uri)->user ); - pj_strdup_with_null( pjsip_pool, &host, &((pjsip_sip_uri *)rxdata->msg_info.from->uri)->host ); - pj_strdup_with_null( pjsip_pool, &destination, &((pjsip_sip_uri *)rxdata->msg_info.to->uri)->host ); + if (PJSIP_URI_SCHEME_IS_SIP(rxdata->msg_info.from->uri)) { + pjsip_sip_uri *sip_uri; - if ( (tech_pvt->caller_profile = switch_caller_profile_new( switch_core_session_get_pool( session ), - username.ptr, - profile->dialplan, - username.ptr, - username.ptr, - host.ptr, - NULL, - NULL, - NULL, - (char *)modname, - NULL, - destination.ptr)) != 0 ) { + sip_uri = pjsip_uri_get_uri(rxdata->msg_info.from->uri); + pj_strdup_with_null( dialog->pool, &username, &sip_uri->user ); + pj_strdup_with_null( dialog->pool, &host, &sip_uri->host ); + } else { + username = pj_str("anonymous"); + username = pj_str("unknown"); + } + + if (PJSIP_URI_SCHEME_IS_SIP(rxdata->msg_info.to->uri)) { + pjsip_sip_uri *sip_uri; + + sip_uri = pjsip_uri_get_uri(rxdata->msg_info.from->uri); + pj_strdup_with_null( dialog->pool, &destination, &sip_uri->user); + } else { + destination = pj_str("unknown"); + } + + tech_pvt->caller_profile = + switch_caller_profile_new( switch_core_session_get_pool( session ), + username.ptr, + profile->dialplan, + username.ptr, + username.ptr, + host.ptr, + NULL, + NULL, + NULL, + (char *)modname, + NULL, + destination.ptr); + if ( tech_pvt->caller_profile != 0 ) { switch_channel_set_caller_profile( channel, tech_pvt->caller_profile ); } @@ -861,51 +994,168 @@ /* Send 100 Trying */ status = pjsip_inv_initial_answer( tech_pvt->sip_invite, rxdata, 100, NULL, NULL, &txdata ); if( status != PJ_SUCCESS ) { - status = pjsip_inv_initial_answer( tech_pvt->sip_invite, rxdata, PJSIP_SC_NOT_ACCEPTABLE, NULL, NULL, &txdata ); + perror_(tech_pvt->sip_invite->dlg->obj_name, "Error in pjsip_inv_initial_answer", status); - if( status == PJ_SUCCESS ) - pjsip_inv_send_msg( tech_pvt->sip_invite, txdata ); - else - pjsip_inv_terminate( tech_pvt->sip_invite, 500, PJ_FALSE ); + pjsip_dlg_respond(dialog, rxdata, 500, NULL, NULL, NULL); + pjsip_inv_terminate(tech_pvt->sip_invite, 500, PJ_FALSE); switch_core_session_destroy( &session ); - return; + + /* unlock (and probably destroy) dialog */ + pjsip_dlg_dec_lock(dialog); + switch_mutex_unlock(tech_pvt->flag_mutex); + goto on_return; } - pjsip_inv_send_msg( tech_pvt->sip_invite, txdata ); + 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, "Error in pjsip_inv_send_msg", status); + pjsip_dlg_respond(dialog, rxdata, 500, NULL, NULL, NULL); + pjsip_inv_terminate(tech_pvt->sip_invite, 500, PJ_FALSE); + + switch_core_session_destroy( &session ); + + /* unlock (and probably destroy) dialog */ + pjsip_dlg_dec_lock(dialog); + switch_mutex_unlock(tech_pvt->flag_mutex); + goto on_return; + } + /* Print the initial SDP to the console / log */ - { + if (0) { char tmp_sdp[1024]; int len = pjmedia_sdp_print( sdp, tmp_sdp, sizeof(tmp_sdp)-1 ); if( len > 0 ) { tmp_sdp[len] = '\0'; - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, - "\n** Our initial SDP **\n%s\n*********************\n", tmp_sdp ); + PJ_LOG(6,(THIS_FILE, + "\n** Our initial SDP **\n%s\n*********************\n", tmp_sdp )); } } - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_INFO, "Starting session thread for call %s\n", tech_pvt->call_id ); + PJ_LOG(4,(THIS_FILE, "Starting session thread for call %s", tech_pvt->call_id )); /* set initial state */ switch_channel_set_state( channel, CS_INIT ); + + /* Ugly hack: force pjsip_inv to negotiate media. */ + status = pjsip_inv_answer( tech_pvt->sip_invite, 183, NULL, NULL, &txdata ); + pjsip_tx_data_dec_ref(txdata); + + /* Send 180 Ring */ + status = pjsip_inv_answer( tech_pvt->sip_invite, 180, NULL, NULL, &txdata ); + if( status != PJ_SUCCESS ) { + perror_(tech_pvt->sip_invite->dlg->obj_name, "pjsip_inv_answer error", status); + + status = pjsip_inv_answer( tech_pvt->sip_invite, PJSIP_SC_NOT_ACCEPTABLE, + NULL, NULL, &txdata ); + + if( status == PJ_SUCCESS ) + pjsip_inv_send_msg( tech_pvt->sip_invite, txdata ); + else + pjsip_inv_terminate( tech_pvt->sip_invite, 500, PJ_FALSE ); + + switch_core_session_destroy( &session ); + goto on_return; + } + 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, "pjsip_inv_send_msg error", status); + switch_core_session_destroy( &session ); + goto on_return; + } + + switch_mutex_unlock(tech_pvt->flag_mutex); switch_core_session_thread_launch( session ); - return; + + /* Done setting up UAS invite session, release lock */ + pjsip_dlg_dec_lock(dialog); + goto on_return; } else { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to create new channel for inbound call\n" ); - return; + perror_(THIS_FILE, "Failed to create new channel for inbound call", -1); + goto on_return; } + +on_return: + TRACE_((THIS_FILE, "LEAVE on_incoming_call")); + } +/* Handle incoming OPTIONS request */ +static void on_incoming_options( pjsip_rx_data *rdata ) +{ + pjsip_tx_data *tdata; + pjsip_response_addr res_addr; + //pjmedia_sdp_session *sdp; + const pjsip_hdr *cap_hdr; + pj_status_t status; + + /* Create basic response. */ + status = pjsip_endpt_create_response(globals.sip_endpt, rdata, 200, NULL, &tdata); + if (status != PJ_SUCCESS) { + return; + } + + /* Add Allow header */ + cap_hdr = pjsip_endpt_get_capability(globals.sip_endpt, PJSIP_H_ALLOW, NULL); + if (cap_hdr) { + pjsip_msg_add_hdr(tdata->msg, pjsip_hdr_clone(tdata->pool, cap_hdr)); + } + + /* Add Accept header */ + cap_hdr = pjsip_endpt_get_capability(globals.sip_endpt, PJSIP_H_ACCEPT, NULL); + if (cap_hdr) { + pjsip_msg_add_hdr(tdata->msg, pjsip_hdr_clone(tdata->pool, cap_hdr)); + } + + /* Add Supported header */ + cap_hdr = pjsip_endpt_get_capability(globals.sip_endpt, PJSIP_H_SUPPORTED, NULL); + if (cap_hdr) { + pjsip_msg_add_hdr(tdata->msg, pjsip_hdr_clone(tdata->pool, cap_hdr)); + } + + /* Add Allow-Events header from the evsub module */ + cap_hdr = pjsip_evsub_get_allow_events_hdr(NULL); + if (cap_hdr) { + pjsip_msg_add_hdr(tdata->msg, pjsip_hdr_clone(tdata->pool, cap_hdr)); + } + + /* Add Server header */ + 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); +#if 0 + status = pjmedia_endpt_create_sdp(pjsua_var.med_endpt, tdata->pool, 1, + &pjsua_var.calls[0].skinfo, &sdp); + if (status == PJ_SUCCESS) { + pjsip_create_sdp_body(tdata->pool, sdp, &tdata->msg->body); + } +#endif + + /* Send response statelessly */ + pjsip_get_response_addr(tdata->pool, rdata, &res_addr); + status = pjsip_endpt_send_response(globals.sip_endpt, &res_addr, tdata, NULL, NULL); + if (status != PJ_SUCCESS) + pjsip_tx_data_dec_ref(tdata); +} + + static pj_bool_t on_rx_request( pjsip_rx_data *rxdata ) { pj_str_t reason; - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "%s: received new request\n", __FUNCTION__ ); + 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 ); return PJ_TRUE; ;; + case PJSIP_OPTIONS_METHOD: + on_incoming_options( rxdata ); + return PJ_TRUE; + ;; default: reason = rxdata->msg_info.msg->line.req.method.name; pjsip_endpt_respond_stateless( rxdata->tp_info.transport->endpt, rxdata, @@ -923,16 +1173,25 @@ assert( inv != NULL && tsx != NULL ); - tech_pvt = inv->mod_data[globals.mod_app.id]; - assert( tech_pvt != NULL ); + if (!(tech_pvt = inv->mod_data[globals.mod_app.id])) { + return; + } + + TRACE_((THIS_FILE, "ENTER call_on_tsx_state_changed")); + + switch_mutex_lock(tech_pvt->flag_mutex); + profile = tech_pvt->profile; assert( profile != NULL ); session = tech_pvt->session; assert( session != NULL ); - if( inv->state == PJSIP_INV_STATE_EARLY && + switch_mutex_unlock(tech_pvt->flag_mutex); + + if( tsx->method.id == PJSIP_INVITE_METHOD && + inv->state == PJSIP_INV_STATE_EARLY && tsx->state == PJSIP_TSX_STATE_PROCEEDING && tsx->status_code == PJSIP_SC_RINGING ) { @@ -941,41 +1200,55 @@ channel = switch_core_session_get_channel( session ); assert( channel != NULL ); - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "* Ring received (call %s)\n", tech_pvt->call_id ); + PJ_LOG(4,(THIS_FILE, "* Ring received (call %s)", tech_pvt->call_id )); } + TRACE_((THIS_FILE, "LEAVE call_on_tsx_state_changed")); } static void call_on_forked( pjsip_inv_session *inv, pjsip_event *evt ) { } /* pjsip callback for inv session state changes */ -static void call_on_state_changed( pjsip_inv_session *inv, - pjsip_event *evt ) +static void call_on_state_changed( pjsip_inv_session *inv, pjsip_event *evt ) { struct private_object *tech_pvt; struct pjsip_profile *profile; switch_core_session_t *session; switch_channel_t *channel; - assert( evt != NULL && inv != NULL ); + assert ( evt != NULL); + assert ( inv != NULL ); + + if (!(tech_pvt = inv->mod_data[globals.mod_app.id])) { + return; + } - tech_pvt = inv->mod_data[globals.mod_app.id]; - assert( tech_pvt != NULL ); + TRACE_((THIS_FILE, "ENTER call_on_state_changed")); + assert( tech_pvt->flag_mutex != NULL ); + + switch_mutex_lock(tech_pvt->flag_mutex); + session = tech_pvt->session; assert ( session != NULL ); profile = tech_pvt->profile; assert( profile != NULL ); + switch_mutex_unlock(tech_pvt->flag_mutex); + + channel = switch_core_session_get_channel( session ); assert( channel != NULL ); + + switch( inv->state ) { case PJSIP_INV_STATE_DISCONNECTED: - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_INFO, "* Call %s (%s) has been disconnected\n", tech_pvt->call_id, - switch_channel_get_name( channel ) ); + inv->mod_data[globals.mod_app.id] = NULL; + 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; @@ -983,14 +1256,22 @@ switch( evt->body.rx_msg.rdata->msg_info.msg->line.status.code ) { 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)); switch_channel_hangup( channel, cause ); + TRACE_((THIS_FILE, "LOOK HERE!!! Leaving switch_channel_hangup")); } break; case PJSIP_INV_STATE_CONFIRMED: - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_INFO, "* Call %s (%s) has been connected\n", tech_pvt->call_id, - switch_channel_get_name( channel ) ); + PJ_LOG(4,(THIS_FILE, "* Call %s (%s) has been connected", tech_pvt->call_id, + switch_channel_get_name( channel ) )); /* -> connected */ if( switch_channel_test_flag( channel, CF_OUTBOUND ) ) { @@ -999,9 +1280,9 @@ break; case PJSIP_INV_STATE_EARLY: - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "* Call %s (%s), state %s\n", tech_pvt->call_id, + PJ_LOG(4,(THIS_FILE, "* Call %s (%s), state %s", tech_pvt->call_id, switch_channel_get_name( channel ), - pjsip_inv_state_name( inv->state ) ); + pjsip_inv_state_name( inv->state ) )); #if 0 /* -> inbound ringing */ @@ -1015,9 +1296,9 @@ break; case PJSIP_INV_STATE_CONNECTING: - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "* Call %s (%s), state %s\n", tech_pvt->call_id, + PJ_LOG(4,(THIS_FILE, "* Call %s (%s), state %s", tech_pvt->call_id, switch_channel_get_name( channel ), - pjsip_inv_state_name( inv->state ) ); + pjsip_inv_state_name( inv->state ) )); #if 0 /* -> outbound ringing */ @@ -1030,16 +1311,18 @@ break; case PJSIP_INV_STATE_CALLING: case PJSIP_INV_STATE_INCOMING: - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "* Call %s (%s), state %s\n", tech_pvt->call_id, + PJ_LOG(4,(THIS_FILE, "* Call %s (%s), state %s", tech_pvt->call_id, switch_channel_get_name( channel ), - pjsip_inv_state_name( inv->state ) ); + pjsip_inv_state_name( inv->state ) )); break; default: - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "* Call %s (%s), UNHANDLED state %s\n", tech_pvt->call_id, + PJ_LOG(4,( THIS_FILE, "* Call %s (%s), UNHANDLED state %s", tech_pvt->call_id, switch_channel_get_name( channel ), - pjsip_inv_state_name( inv->state ) ); + pjsip_inv_state_name( inv->state ) )); break; } + + TRACE_((THIS_FILE, "LEAVE call_on_state_changed")); } /* pjsip callback for sdp negotiation changes */ @@ -1057,11 +1340,15 @@ int ms, rate; pj_sockaddr addr; + TRACE_((THIS_FILE, "ENTER call_on_media_update")); + tech_pvt = inv->mod_data[globals.mod_app.id]; assert( tech_pvt != NULL ); + switch_mutex_lock(tech_pvt->flag_mutex); profile = tech_pvt->profile; assert( profile != NULL ); + switch_mutex_unlock(tech_pvt->flag_mutex); pool = inv->dlg->pool; assert( pool != NULL ); @@ -1072,23 +1359,24 @@ channel = switch_core_session_get_channel( tech_pvt->session ); assert( channel != NULL ); - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "-- SDP negotiation status change %s (state %s, status %d)\n", tech_pvt->call_id, - pjmedia_sdp_neg_state_str(pjmedia_sdp_neg_get_state( inv->neg )), status ); + PJ_LOG(4,(THIS_FILE, "-- SDP negotiation status change %s (state %s, status %d)", tech_pvt->call_id, + pjmedia_sdp_neg_state_str(pjmedia_sdp_neg_get_state( inv->neg )), status )); if( pjmedia_sdp_neg_get_state( inv->neg ) != PJMEDIA_SDP_NEG_STATE_DONE ) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "---- SDP negotiation still ongoing for call %s\n", tech_pvt->call_id ); + PJ_LOG(4,( THIS_FILE, "---- SDP negotiation still ongoing for call %s", tech_pvt->call_id )); } if( status != PJ_SUCCESS ) { char tmp[1024]; pj_strerror( status, tmp, sizeof(tmp) ); - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "SDP negotiation failed for call %s, reason: %s\n", tech_pvt->call_id, 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 ); + TRACE_((THIS_FILE, "LEAVE call_on_media_update")); return; } if( tech_pvt->rtp_session ) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "SDP re-negotiation received %s\n", tech_pvt->call_id ); + PJ_LOG(1,(THIS_FILE, "SDP re-negotiation received %s", tech_pvt->call_id )); stop_rtp( tech_pvt ); switch_clear_flag_locked( tech_pvt, TFLAG_IO ); @@ -1104,33 +1392,42 @@ pjmedia_sdp_neg_get_active_remote( inv->neg, &remote_sdp ); /* Print the final(?) SDPs to the console / log */ - { + if (0) { char tmp_sdp[1024]; int len; len = pjmedia_sdp_print( local_sdp, tmp_sdp, sizeof(tmp_sdp)-1 ); if( len > 0 ) { tmp_sdp[len] = '\0'; - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, - "\n** Our final SDP **\n%s\n*********************\n", tmp_sdp ); + PJ_LOG(5,(THIS_FILE, + "\n** Our final SDP **\n%s\n*********************\n", tmp_sdp )); } len = pjmedia_sdp_print( remote_sdp, tmp_sdp, sizeof(tmp_sdp)-1 ); if( len > 0 ) { tmp_sdp[len] = '\0'; - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, - "\n** Remote final SDP **\n%s\n*************************\n", tmp_sdp ); + PJ_LOG(5,(THIS_FILE, + "\n** Remote final SDP **\n%s\n*************************\n", tmp_sdp )); } } + /* Check if call is put on hold. */ + if (local_sdp->media_count == 0 || + pjmedia_sdp_media_find_attr2(local_sdp->media[0], "inactive", NULL) != NULL) + { + //PJ_TODO(HANDLE_CALL_HOLD); + } + + /* retrieve stream (= codec) information */ status = mod_pjsip_codec_from_sdp( tech_pvt, pool, local_sdp, remote_sdp, 0, &codec, &imp ); if( status != PJ_SUCCESS ) { /* No valid codec found */ - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "SDP negotation failed, codec unknown\n" ); + perror_(THIS_FILE, "SDP negotation failed, codec unknown", status ); switch_set_flag_locked( tech_pvt, TFLAG_BYE ); switch_clear_flag_locked( tech_pvt, TFLAG_IO ); switch_channel_hangup( channel, SWITCH_CAUSE_DESTINATION_OUT_OF_ORDER ); + TRACE_((THIS_FILE, "LEAVE call_on_media_update")); return; } @@ -1138,7 +1435,7 @@ rate = imp->bits_per_second / 8; ms = imp->microseconds_per_frame / 1000; - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "Codec %s, rate: %d, ms per frame: %d\n", codec->iananame, rate, ms ); + PJ_LOG(4,(THIS_FILE, "Codec %s, rate: %d, ms per frame: %d", codec->iananame, rate, ms )); /* initialize codecs */ ret = switch_core_codec_init(&tech_pvt->read_codec, codec->iananame, rate, ms, 1, @@ -1146,8 +1443,9 @@ NULL, switch_core_session_get_pool( session )); if( ret != SWITCH_STATUS_SUCCESS ) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to initialize read codec\n" ); + perror_(THIS_FILE, "Failed to initialize read codec", -1); switch_channel_hangup( channel, SWITCH_CAUSE_DESTINATION_OUT_OF_ORDER ); + TRACE_((THIS_FILE, "LEAVE call_on_media_update")); return; } @@ -1156,8 +1454,9 @@ NULL, switch_core_session_get_pool( session )); if( ret != SWITCH_STATUS_SUCCESS ) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to initialize write codec\n" ); + perror_(THIS_FILE, "ERROR: Failed to initialize write codec", -1 ); switch_channel_hangup( channel, SWITCH_CAUSE_DESTINATION_OUT_OF_ORDER ); + TRACE_((THIS_FILE, "LEAVE call_on_media_update")); return; } @@ -1170,7 +1469,7 @@ /* update remote rtp IP and port, restart rtp */ status = mod_pjsip_addr_from_sdp( remote_sdp, 0, &addr ); if( status != PJ_SUCCESS ) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to get remote RTP endpoint address and port\n" ); + perror_(THIS_FILE, "Failed to get remote RTP endpoint address and port", status); switch_channel_hangup( channel, SWITCH_CAUSE_DESTINATION_OUT_OF_ORDER ); } else { pj_in_addr tmp_addr; @@ -1180,16 +1479,20 @@ strncpy( tech_pvt->remote_sdp_audio_addr, pj_inet_ntoa( tmp_addr ), sizeof(tech_pvt->remote_sdp_audio_addr) ); } - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "Codec %s, %s:%d\n", codec->iananame, tech_pvt->remote_sdp_audio_addr, tech_pvt->remote_sdp_audio_port ); + PJ_LOG(4,(THIS_FILE, "Codec %s, %s:%d", codec->iananame, + tech_pvt->remote_sdp_audio_addr, tech_pvt->remote_sdp_audio_port )); /* start rtp */ start_rtp( tech_pvt ); /* activate io */ switch_set_flag_locked( tech_pvt, TFLAG_IO ); + + TRACE_((THIS_FILE, "LEAVE call_on_media_update")); } -static switch_status_t pjsip_receive_message(switch_core_session_t *session, switch_core_session_message_t *msg) +static switch_status_t pjsip_receive_message(switch_core_session_t *session, + switch_core_session_message_t *msg) { struct private_object *tech_pvt; switch_channel_t *channel; @@ -1222,16 +1525,19 @@ /* Send 183 Session Progress */ status = pjsip_inv_answer( tech_pvt->sip_invite, 183, NULL, NULL, &txdata ); if( status != PJ_SUCCESS ) { - status = pjsip_inv_answer( tech_pvt->sip_invite, PJSIP_SC_NOT_ACCEPTABLE, NULL, NULL, &txdata ); + status = pjsip_inv_answer( tech_pvt->sip_invite, PJSIP_SC_NOT_ACCEPTABLE, + NULL, NULL, &txdata ); - if( status == PJ_SUCCESS ) + if( status == PJ_SUCCESS ) { + add_server_header(txdata); pjsip_inv_send_msg( tech_pvt->sip_invite, txdata ); - else + } else pjsip_inv_terminate( tech_pvt->sip_invite, 500, PJ_FALSE ); switch_core_session_destroy( &session ); return SWITCH_STATUS_GENERR; } + add_server_header(txdata); pjsip_inv_send_msg( tech_pvt->sip_invite, txdata ); } switch_channel_set_flag( channel, CF_EARLY_MEDIA ); @@ -1295,7 +1601,8 @@ media->desc.port_count = 1; media->desc.transport = pj_str( "RTP/AVP" ); - strncpy( tech_pvt->local_sdp_audio_addr, profile->local_addr, sizeof(tech_pvt->local_sdp_audio_addr) ); + strncpy( tech_pvt->local_sdp_audio_addr, profile->local_addr, + sizeof(tech_pvt->local_sdp_audio_addr) ); /* codec rtpmap list */ media->desc.fmt_count = 0; @@ -1374,20 +1681,24 @@ assert( tech_pvt != NULL ); + TRACE_((THIS_FILE, "ENTER start_rtp")); + channel = switch_core_session_get_channel( tech_pvt->session ); assert( channel != NULL ); if( tech_pvt->rtp_session ) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "RTP already initialized %s\n", tech_pvt->call_id ); + PJ_LOG(4,(THIS_FILE, "RTP already initialized %s", tech_pvt->call_id )); + TRACE_((THIS_FILE, "LEAVE start_rtp")); return SWITCH_STATUS_SUCCESS; } - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "Starting RTP for call %s\n", tech_pvt->call_id ); + PJ_LOG(4,(THIS_FILE, "Starting RTP for call %s", tech_pvt->call_id )); rate = tech_pvt->read_codec.implementation->bits_per_second; ms = tech_pvt->read_codec.implementation->microseconds_per_frame; - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, "RTP parameters for call %s: src (%s:%d) -> dst (%s:%d), using codec %s @ %d b/s, framelen %d ms\n", + switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG, + "RTP parameters for call %s: src (%s:%d) -> dst (%s:%d), using codec %s @ %d b/s, framelen %d ms\n", tech_pvt->call_id, tech_pvt->local_sdp_audio_addr, tech_pvt->local_sdp_audio_port, @@ -1411,8 +1722,10 @@ &err, switch_core_session_get_pool( tech_pvt->session ) ); if( !tech_pvt->rtp_session ) { + PJ_LOG(1,(THIS_FILE, "RTP ERROR [%s]", err)); switch_channel_hangup( channel, SWITCH_CAUSE_DESTINATION_OUT_OF_ORDER ); switch_set_flag_locked( tech_pvt, TFLAG_BYE ); + TRACE_((THIS_FILE, "LEAVE start_rtp")); return SWITCH_STATUS_FALSE; } @@ -1420,6 +1733,7 @@ switch_set_flag_locked( tech_pvt, TFLAG_IO); + TRACE_((THIS_FILE, "LEAVE start_rtp")); return SWITCH_STATUS_SUCCESS; } @@ -1430,6 +1744,8 @@ if( !tech_pvt->rtp_session ) return SWITCH_STATUS_SUCCESS; + TRACE_((THIS_FILE, "ENTER stop_rtp")); + while( loop < 10 && ( switch_test_flag( tech_pvt, TFLAG_READING ) || switch_test_flag( tech_pvt, TFLAG_WRITING ) ) ) @@ -1438,9 +1754,12 @@ loop++; } + switch_mutex_lock(tech_pvt->flag_mutex); switch_rtp_destroy( &tech_pvt->rtp_session ); tech_pvt->rtp_session = NULL; - + switch_mutex_unlock(tech_pvt->flag_mutex); + + TRACE_((THIS_FILE, "LEAVE stop_rtp")); return SWITCH_STATUS_SUCCESS; } @@ -1465,7 +1784,8 @@ } if( !(profile = switch_core_alloc( module_pool, sizeof(struct pjsip_profile))) ) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_CRIT, "Failed to allocate new profile %s\n", profile_name ); + switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_CRIT, + "Failed to allocate new profile %s\n", profile_name ); result = SWITCH_STATUS_TERM; goto out; } @@ -1488,7 +1808,8 @@ pj_str_t tmp; if( !pj_inet_aton( pj_cstr( &tmp, val ), &profile->sip_addr.sin_addr ) ) { - switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Invalid address: %s\n", val ); + switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, + "Invalid address: %s\n", val ); result = SWITCH_STATUS_TERM; goto out; } @@ -1585,6 +1906,88 @@ return SWITCH_STATUS_SUCCESS; } + +/***************************************************************************** + * This is a very simple PJSIP module, whose sole purpose is to display + * incoming and outgoing messages to log. This module will have priority + * higher than transport layer, which means: + * + * - incoming messages will come to this module first before reaching + * transaction layer. + * + * - outgoing messages will come to this module last, after the message + * has been 'printed' to contiguous buffer by transport layer and + * appropriate transport instance has been decided for this message. + * + */ + +/* Notification on incoming messages */ +static pj_bool_t logging_on_rx_msg(pjsip_rx_data *rdata) +{ + PJ_LOG(5,(THIS_FILE, "RX %d bytes %s from %s %s:%d:\n" + "%.*s\n" + "--end msg--", + rdata->msg_info.len, + pjsip_rx_data_get_info(rdata), + rdata->tp_info.transport->type_name, + rdata->pkt_info.src_name, + rdata->pkt_info.src_port, + (int)rdata->msg_info.len, + rdata->msg_info.msg_buf)); + + /* Always return false, otherwise messages will not get processed! */ + return PJ_FALSE; +} + +/* Notification on outgoing messages */ +static pj_status_t logging_on_tx_msg(pjsip_tx_data *tdata) +{ + + /* Important note: + * tp_info field is only valid after outgoing messages has passed + * transport layer. So don't try to access tp_info when the module + * has lower priority than transport layer. + */ + + PJ_LOG(5,(THIS_FILE, "TX %d bytes %s to %s %s:%d:\n" + "%.*s\n" + "--end msg--", + (tdata->buf.cur - tdata->buf.start), + pjsip_tx_data_get_info(tdata), + tdata->tp_info.transport->type_name, + tdata->tp_info.dst_name, + tdata->tp_info.dst_port, + (int)(tdata->buf.cur - tdata->buf.start), + tdata->buf.start)); + + /* Always return success, otherwise message will not get sent! */ + return PJ_SUCCESS; +} + +/* The module instance. */ +static pjsip_module pjsua_msg_logger = +{ + NULL, NULL, /* prev, next. */ + { "mod-pjsua-log", 13 }, /* Name. */ + -1, /* Id */ + PJSIP_MOD_PRIORITY_TRANSPORT_LAYER-1,/* Priority */ + NULL, /* load() */ + NULL, /* start() */ + NULL, /* stop() */ + NULL, /* unload() */ + &logging_on_rx_msg, /* on_rx_request() */ + &logging_on_rx_msg, /* on_rx_response() */ + &logging_on_tx_msg, /* on_tx_request. */ + &logging_on_tx_msg, /* on_tx_response() */ + NULL, /* on_tsx_state() */ + +}; + + + + + + SWITCH_MOD_DECLARE(switch_status_t) switch_module_runtime(void) { switch_hash_index_t *p_entry; @@ -1597,7 +2000,8 @@ return SWITCH_STATUS_TERM; } - pj_log_set_level(0); + pj_log_set_log_func(log_func); + pj_log_set_level(4); /* next: pjlib_util */ status = pjlib_util_init(); @@ -1616,6 +2020,9 @@ return SWITCH_STATUS_TERM; } + /* Initialize server name */ + pj_strdup2_with_null(pjsip_pool, &FREESWITCH_SERVER, "FreeSWITCH (mod_pjsip)"); + if( config_pjsip( ) != SWITCH_STATUS_SUCCESS ) { switch_log_printf( SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to load configuration\n" ); return SWITCH_STATUS_TERM; @@ -1635,6 +2042,11 @@ invite_cb.on_tsx_state_changed = &call_on_tsx_state_changed; /* + * Register logger module. + */ + pjsip_endpt_register_module(globals.sip_endpt, &pjsua_msg_logger); + + /* * */ for( p_entry = switch_hash_first( module_pool, globals.profiles_hash ); p_entry; p_entry = switch_hash_next( p_entry ) ) @@ -1747,7 +2159,9 @@ globals.running = 1; while ( globals.running > 0 ) { pj_time_val timeout = { 1, 0 }; + TRACE_((THIS_FILE, "ENTER pjsip_endpt_handle_events")); pjsip_endpt_handle_events( globals.sip_endpt, &timeout ); + TRACE_((THIS_FILE, "LEAVE pjsip_endpt_handle_events")); } globals.running = 0; @@ -1755,3 +2169,4 @@ return SWITCH_STATUS_TERM; } + Modified: freeswitch/branches/bennylp/src/mod/endpoints/mod_pjsip/mod_pjsip_sdp.c ============================================================================== --- freeswitch/branches/bennylp/src/mod/endpoints/mod_pjsip/mod_pjsip_sdp.c (original) +++ freeswitch/branches/bennylp/src/mod/endpoints/mod_pjsip/mod_pjsip_sdp.c Fri Aug 11 14:24:06 2006 @@ -21,7 +21,7 @@ #include <switch.h> #include <pjlib.h> #include <pjsip_ua.h> -#include <pjsdp.h> +#include <pjmedia.h> #include "mod_pjsip.h"