freetdm: improved logic to enable/disable EC on call start/stop

         - MFC-R2 requires tone signaling that gets screwed sometimes
           if the EC is enabled during call setup.
         - EC is now enabled only when switching to a state requiring
         media (UP and PROGRESS_MEDIA)
         - The logic is aware of EC persist option in Wanpipe
         - Improved logging in ftmod_wanpipe to print EC state on startup

libs/freetdm/src/ftdm_io.c

@@ -404,39 +404,39 @@ static __inline__ void ftdm_std_free(void *pool, void *ptr)
 	free(ptr);
 }
 
-static void ftdm_set_echocancel_call_begin(ftdm_channel_t *chan)
+FT_DECLARE(void) ftdm_set_echocancel_call_begin(ftdm_channel_t *chan)
 {
 	ftdm_caller_data_t *caller_data = ftdm_channel_get_caller_data(chan);
 	if (ftdm_channel_test_feature(chan, FTDM_CHANNEL_FEATURE_HWEC)) {
 		if (ftdm_channel_test_feature(chan, FTDM_CHANNEL_FEATURE_HWEC_DISABLED_ON_IDLE)) {
+			/* If the ec is disabled on idle, we need to enable it unless is a digital call */
 			if (caller_data->bearer_capability != FTDM_BEARER_CAP_64K_UNRESTRICTED) {
+				ftdm_log_chan(chan, FTDM_LOG_DEBUG, "Enabling ec for call in channel state %s\n", ftdm_channel_state2str(chan->state));
 				ftdm_channel_command(chan, FTDM_COMMAND_ENABLE_ECHOCANCEL, NULL);
 			}
 		} else {
+			/* If the ec is enabled on idle, we do nothing unless is a digital call that needs it disabled */
 			if (caller_data->bearer_capability == FTDM_BEARER_CAP_64K_UNRESTRICTED) {
+				ftdm_log_chan(chan, FTDM_LOG_DEBUG, "Disabling ec for digital call in channel state %s\n", ftdm_channel_state2str(chan->state));
 				ftdm_channel_command(chan, FTDM_COMMAND_DISABLE_ECHOCANCEL, NULL);
 			}
 		}
 	}
 }
 
-static void ftdm_set_echocancel_call_end(ftdm_channel_t *chan)
+FT_DECLARE(void) ftdm_set_echocancel_call_end(ftdm_channel_t *chan)
 {
-	ftdm_caller_data_t *caller_data = ftdm_channel_get_caller_data(chan);
 	if (ftdm_channel_test_feature(chan, FTDM_CHANNEL_FEATURE_HWEC)) {
 		if (ftdm_channel_test_feature(chan, FTDM_CHANNEL_FEATURE_HWEC_DISABLED_ON_IDLE)) {
-			if (caller_data->bearer_capability != FTDM_BEARER_CAP_64K_UNRESTRICTED) {
-				ftdm_channel_command(chan, FTDM_COMMAND_DISABLE_ECHOCANCEL, NULL);
-			}
+			ftdm_log_chan(chan, FTDM_LOG_DEBUG, "Disabling ec on call end in channel state %s\n", ftdm_channel_state2str(chan->state));
+			ftdm_channel_command(chan, FTDM_COMMAND_DISABLE_ECHOCANCEL, NULL);
 		} else {
-			if (caller_data->bearer_capability == FTDM_BEARER_CAP_64K_UNRESTRICTED) {
-				ftdm_channel_command(chan, FTDM_COMMAND_ENABLE_ECHOCANCEL, NULL);
-			}
+			ftdm_log_chan(chan, FTDM_LOG_DEBUG, "Enabling ec back on call end in channel state %s\n", ftdm_channel_state2str(chan->state));
+			ftdm_channel_command(chan, FTDM_COMMAND_ENABLE_ECHOCANCEL, NULL);
 		}
 	}
 }
 
-
 FT_DECLARE_DATA ftdm_memory_handler_t g_ftdm_mem_handler = 
 {
 	/*.pool =*/ NULL,
@@ -5548,25 +5548,44 @@ FT_DECLARE(ftdm_status_t) ftdm_span_send_signal(ftdm_span_t *span, ftdm_sigmsg_t
 
 	case FTDM_SIGEVENT_PROGRESS_MEDIA:
 		{
-			ftdm_log_chan_msg(sigmsg->channel, FTDM_LOG_DEBUG, "Enabling echo cancellation on progress media\n");
-			ftdm_set_echocancel_call_begin(sigmsg->channel);
+			/* test signaling module compliance */
+			if (sigmsg->channel->state != FTDM_CHANNEL_STATE_PROGRESS_MEDIA) {
+				ftdm_log_chan(sigmsg->channel, FTDM_LOG_WARNING, "FTDM_SIGEVENT_PROGRESS_MEDIA sent in state %s\n", ftdm_channel_state2str(sigmsg->channel->state));
+			}
 		}
 		break;
 
-	case FTDM_SIGEVENT_STOP:
-		if (!ftdm_test_flag(sigmsg->channel, FTDM_CHANNEL_CALL_STARTED)) {
-			/* this happens for FXS devices which blindly send SIGEVENT_STOP, we should fix it there ... */
-			ftdm_log_chan_msg(sigmsg->channel, FTDM_LOG_DEBUG, "Ignoring SIGEVENT_STOP since user never knew about a call in this channel\n");
-			goto done;
-		}
-		if (ftdm_test_flag(sigmsg->channel, FTDM_CHANNEL_USER_HANGUP)) {
-			ftdm_log_chan_msg(sigmsg->channel, FTDM_LOG_DEBUG, "Ignoring SIGEVENT_STOP since user already requested hangup\n");
-			goto done;
+	case FTDM_SIGEVENT_UP:
+		{
+			/* test signaling module compliance */
+			if (sigmsg->channel->state != FTDM_CHANNEL_STATE_UP) {
+				ftdm_log_chan(sigmsg->channel, FTDM_LOG_WARNING, "FTDM_SIGEVENT_UP sent in state %s\n", ftdm_channel_state2str(sigmsg->channel->state));
+			}
 		}
-		if (sigmsg->channel->state == FTDM_CHANNEL_STATE_TERMINATING) {
-			ftdm_log_chan_msg(sigmsg->channel, FTDM_LOG_DEBUG, "Scheduling safety hangup timer\n");
-			/* if the user does not move us to hangup in 2 seconds, we will do it ourselves */
-			ftdm_sched_timer(globals.timingsched, "safety-hangup", FORCE_HANGUP_TIMER, execute_safety_hangup, sigmsg->channel, &sigmsg->channel->hangup_timer);
+		break;
+
+	case FTDM_SIGEVENT_STOP:
+		{
+			/* TODO: we could test for compliance here and check the state is FTDM_CHANNEL_STATE_TERMINATING
+			 * but several modules need to be updated first */
+
+			/* if the call was never started, do not send SIGEVENT_STOP
+			   this happens for FXS devices in ftmod_analog which blindly send SIGEVENT_STOP, we should fix it there ... */
+			if (!ftdm_test_flag(sigmsg->channel, FTDM_CHANNEL_CALL_STARTED)) {
+				ftdm_log_chan_msg(sigmsg->channel, FTDM_LOG_DEBUG, "Ignoring SIGEVENT_STOP since user never knew about a call in this channel\n");
+				goto done;
+			}
+
+			if (ftdm_test_flag(sigmsg->channel, FTDM_CHANNEL_USER_HANGUP)) {
+				ftdm_log_chan_msg(sigmsg->channel, FTDM_LOG_DEBUG, "Ignoring SIGEVENT_STOP since user already requested hangup\n");
+				goto done;
+			}
+
+			if (sigmsg->channel->state == FTDM_CHANNEL_STATE_TERMINATING) {
+				ftdm_log_chan_msg(sigmsg->channel, FTDM_LOG_DEBUG, "Scheduling safety hangup timer\n");
+				/* if the user does not move us to hangup in 2 seconds, we will do it ourselves */
+				ftdm_sched_timer(globals.timingsched, "safety-hangup", FORCE_HANGUP_TIMER, execute_safety_hangup, sigmsg->channel, &sigmsg->channel->hangup_timer);
+			}
 		}
 		break;
 

libs/freetdm/src/ftdm_state.c

@@ -70,13 +70,13 @@ FT_DECLARE(ftdm_status_t) _ftdm_channel_complete_state(const char *file, const c
 
 	if (state == FTDM_CHANNEL_STATE_PROGRESS) {
 		ftdm_set_flag(fchan, FTDM_CHANNEL_PROGRESS);
+	} else if (state == FTDM_CHANNEL_STATE_PROGRESS_MEDIA) {
+		ftdm_set_flag(fchan, FTDM_CHANNEL_PROGRESS);	
+		ftdm_test_and_set_media(fchan);
 	} else if (state == FTDM_CHANNEL_STATE_UP) {
 		ftdm_set_flag(fchan, FTDM_CHANNEL_PROGRESS);
-		ftdm_set_flag(fchan, FTDM_CHANNEL_MEDIA);	
 		ftdm_set_flag(fchan, FTDM_CHANNEL_ANSWERED);	
-	} else if (state == FTDM_CHANNEL_STATE_PROGRESS_MEDIA) {
-		ftdm_set_flag(fchan, FTDM_CHANNEL_PROGRESS);	
-		ftdm_set_flag(fchan, FTDM_CHANNEL_MEDIA);	
+		ftdm_test_and_set_media(fchan);
 	} else if (state == FTDM_CHANNEL_STATE_DIALING) {
 		ftdm_sigmsg_t msg;
 		memset(&msg, 0, sizeof(msg));

libs/freetdm/src/ftmod/ftmod_r2/ftmod_r2.c

@@ -647,9 +647,6 @@ static void ftdm_r2_on_call_init(openr2_chan_t *r2chan)
 		return;
 	}
 
-	/* mark the channel in use (so no outgoing calls can be placed here) */
-	ftdm_channel_use(ftdmchan);	
-
 	memset(ftdmchan->caller_data.dnis.digits, 0, sizeof(ftdmchan->caller_data.collected));
 	memset(ftdmchan->caller_data.ani.digits, 0, sizeof(ftdmchan->caller_data.collected));
 

libs/freetdm/src/ftmod/ftmod_wanpipe/ftmod_wanpipe.c

@@ -230,6 +230,8 @@ static unsigned wp_open_range(ftdm_span_t *span, unsigned spanno, unsigned start
 		ftdm_channel_t *chan;
 		ftdm_socket_t sockfd = FTDM_INVALID_SOCKET;
 		const char *dtmf = "none";
+		const char *hwec_str = "none";
+		const char *hwec_idle = "none";
 		if (!strncasecmp(span->name, "smg_prid_nfas", 8) && span->trunk_type == FTDM_TRUNK_T1 && x == 24) {
 #ifdef LIBSANGOMA_VERSION
 			sockfd = __tdmv_api_open_span_chan(spanno, x);
@@ -271,6 +273,8 @@ static unsigned wp_open_range(ftdm_span_t *span, unsigned spanno, unsigned start
 			|| type == FTDM_CHAN_TYPE_B) {
 				int err;
 				
+				hwec_str = "unavailable";
+				hwec_idle = "enabled";
 				dtmf = "software";
 
 				err = sangoma_tdm_get_hw_coding(chan->sockfd, &tdm_api);
@@ -289,6 +293,7 @@ static unsigned wp_open_range(ftdm_span_t *span, unsigned spanno, unsigned start
 
 				err = sangoma_tdm_get_hw_ec(chan->sockfd, &tdm_api);
 				if (err > 0) {
+					hwec_str = "available";
 					ftdm_channel_set_feature(chan, FTDM_CHANNEL_FEATURE_HWEC);
 				}
 				
@@ -296,6 +301,7 @@ static unsigned wp_open_range(ftdm_span_t *span, unsigned spanno, unsigned start
 				err = sangoma_tdm_get_hwec_persist_status(chan->sockfd, &tdm_api);
 				if (err == 0) {
 					ftdm_channel_set_feature(chan, FTDM_CHANNEL_FEATURE_HWEC_DISABLED_ON_IDLE);
+					hwec_idle = "disabled";
 				}
 #else
 				if (span->trunk_type ==  FTDM_TRUNK_BRI || span->trunk_type ==  FTDM_TRUNK_BRI_PTMP) {
@@ -365,7 +371,8 @@ static unsigned wp_open_range(ftdm_span_t *span, unsigned spanno, unsigned start
 				ftdm_copy_string(chan->chan_number, number, sizeof(chan->chan_number));
 			}
 			configured++;
-			ftdm_log_chan(chan, FTDM_LOG_INFO, "Configured wanpipe device fd:%d DTMF: %s\n", sockfd, dtmf);
+			ftdm_log_chan(chan, FTDM_LOG_INFO, "Configured wanpipe device FD: %d, DTMF: %s, HWEC: %s, HWEC_IDLE: %s\n", 
+					sockfd, dtmf, hwec_str, hwec_idle);
 
 		} else {
 			ftdm_log(FTDM_LOG_ERROR, "ftdm_span_add_channel failed for wanpipe span %d channel %d\n", spanno, x);

libs/freetdm/src/include/private/ftdm_core.h

@@ -622,6 +622,9 @@ FT_DECLARE(ftdm_status_t) ftdm_span_trigger_signals(const ftdm_span_t *span);
 /*! \brief clear the tone detector state */
 FT_DECLARE(void) ftdm_channel_clear_detected_tones(ftdm_channel_t *ftdmchan);
 
+/* start/stop echo cancelling at the beginning/end of a call */
+FT_DECLARE(void) ftdm_set_echocancel_call_begin(ftdm_channel_t *chan);
+FT_DECLARE(void) ftdm_set_echocancel_call_end(ftdm_channel_t *chan);
 
 /*!
   \brief Assert condition
@@ -677,6 +680,14 @@ FT_DECLARE(void) ftdm_channel_clear_detected_tones(ftdm_channel_t *ftdmchan);
 #define ftdm_span_lock(span) ftdm_mutex_lock(span->mutex)
 #define ftdm_span_unlock(span) ftdm_mutex_unlock(span->mutex)
 
+#define ftdm_test_and_set_media(fchan) \
+		do { \
+			if (!ftdm_test_flag((fchan), FTDM_CHANNEL_MEDIA)) { \
+				ftdm_set_flag((fchan), FTDM_CHANNEL_MEDIA); \
+				ftdm_set_echocancel_call_begin((fchan)); \
+			} \
+		} while (0);
+
 FT_DECLARE_DATA extern const char *FTDM_LEVEL_NAMES[9];
 
 static __inline__ void ftdm_abort(void)

libs/freetdm/src/include/private/ftdm_types.h

@@ -227,16 +227,11 @@ typedef enum {
 #define FTDM_CHANNEL_OUTBOUND        (1ULL << 18)
 #define FTDM_CHANNEL_SUSPENDED       (1ULL << 19)
 #define FTDM_CHANNEL_3WAY            (1ULL << 20)
-
-/* this 3 flags are really nonsense used by boost module only, as soon
- * as we deprecate/delete boost module we can get rid of them 
- * ==================
- * */
 #define FTDM_CHANNEL_PROGRESS        (1ULL << 21)
+/*!< There is media on the channel already */
 #define FTDM_CHANNEL_MEDIA           (1ULL << 22)
+/*!< The channel was answered */
 #define FTDM_CHANNEL_ANSWERED        (1ULL << 23)
-/* ================== */
-
 #define FTDM_CHANNEL_MUTE            (1ULL << 24)
 #define FTDM_CHANNEL_USE_RX_GAIN     (1ULL << 25)
 #define FTDM_CHANNEL_USE_TX_GAIN     (1ULL << 26)