freetdm: initial glare handling code

libs/freetdm/docs/glare.txt

@@ -0,0 +1,29 @@
+Glare is a PITA.
+
+Although configuration of ISDN links can be done to minimize glare, to be pedantic we must have a clear policy
+on how the FreeTDM API is supposed to behave on glare across signaling modules.
+
+There is a well-known race in the FreeTDM API since the beginning. When a user wants to place a call there is 2 APIs that
+must be used:
+
+1. ftdm_channel_open_xx (to hunt the channel by group, span or select a channel individually)
+2. ftdm_channel_call_place() to place the actual call.
+
+Since the user has no access to channel locking, between opening a channel and placing a call, an incoming call could be
+received. Therefore the user needs to be aware of the following:
+
+1. Between ftdm_channel_open_xx and ftdm_channel_call_place() a SIGEVENT_START can be received, if the user application
+is smart enough, upon receive of SIGEVENT_START it can avoid doing anything else with the channel (from an outgoing call perspective) 
+since that channel is now a channel owned by the incoming call. It can for example hunt another channel using 
+ftdm_channel_open_xx again and avoid calling ftdm_channel_call_place. However, if the app is not smart enough and still calls
+ftdm_channel_call_place even though already received FTDM_SIGEVENT_START on that channel, ftdm_channel_call_place will return
+FTDM_BREAK to inform the user the outgoing call could not be placed and that there is already an incoming call on that channel.
+
+2. If SIGEVENT_START was not received before calling ftdm_channel_call_place, it could still come while ftdm_channel_call_place()
+is being executed, in such situation ftdm_channel_place_call() will return FTDM_BREAK to inform the user the call could
+not be placed due to glare and the incoming call won the channel, he user should back off since the channel is
+now owned by the incoming call (it can touch the channel having in mind there is now an incoming call on it)
+
+3. After ftdm_channel_call_place returns, if glare is detected and the signaling stack decides to drop the local call, a regular
+SIGEVENT_STOP will be sent with the hangup cause FTDM_CAUSE_REQUESTED_CHAN_UNAVAIL.
+

libs/freetdm/src/ftdm_io.c

@@ -2142,6 +2142,10 @@ static ftdm_status_t _ftdm_channel_call_hangup_nl(ftdm_channel_t *chan, const ch
 			ftdm_sched_cancel_timer(globals.timingsched, chan->hangup_timer);
 		}
 		ftdm_set_flag(chan, FTDM_CHANNEL_USER_HANGUP);
+		/* if a state change requested by the user was pending, a hangup certainly cancels that request  */
+		if (ftdm_test_flag(chan, FTDM_CHANNEL_STATE_CHANGE)) {
+			ftdm_channel_cancel_state(file, func, line, chan);
+		}
 		status = ftdm_channel_set_state(file, func, line, chan, FTDM_CHANNEL_STATE_HANGUP, 1);
 	} else {
 		/* the signaling stack did not touch the state, 
@@ -2372,19 +2376,57 @@ FT_DECLARE(ftdm_status_t) _ftdm_channel_call_place(const char *file, const char
 
 	ftdm_channel_lock(ftdmchan);
 
-	if (ftdmchan->span->outgoing_call) {
+	if (!ftdmchan->span->outgoing_call) {
-		status = ftdmchan->span->outgoing_call(ftdmchan);
+		ftdm_log_chan_msg(ftdmchan, FTDM_LOG_ERROR, "outgoing_call method not implemented in this span!\n");
-	} else {
+		status = FTDM_ENOSYS;
-		status = FTDM_NOTIMPL;
+		goto done;
-		ftdm_log(FTDM_LOG_ERROR, "outgoing_call method not implemented in this span!\n");
 	}
 
-	if (status == FTDM_SUCCESS) {
+	if (!ftdm_test_flag(ftdmchan, FTDM_CHANNEL_OPEN)) {
-		ftdm_set_flag(ftdmchan, FTDM_CHANNEL_CALL_STARTED);
+		ftdm_log_chan_msg(ftdmchan, FTDM_LOG_ERROR, "Cannot place call in channel that is not open!\n");
-		ftdm_call_set_call_id(ftdmchan, &ftdmchan->caller_data);
+		goto done;
+	}
+
+	if (!ftdm_test_flag(ftdmchan, FTDM_CHANNEL_OUTBOUND)) {
+		if (ftdm_test_flag(ftdmchan, FTDM_CHANNEL_CALL_STARTED)) {
+			status = FTDM_BREAK;
+			/* we set the outbound flag when the user open a channel, but if the signaling stack sends an
+			 * incoming call we clear it, which indicates the inbound call was received before we could try
+			 * to place the outbound call */
+			ftdm_log_chan_msg(ftdmchan, FTDM_LOG_WARNING, "Inbound call won the race, you should hunt in another channel!\n");
+			goto done;
+		} 
+		ftdm_log_chan(ftdmchan, FTDM_LOG_ERROR, "Cannot place call in non outbound channel in state %s!\n", ftdm_channel_state2str(ftdmchan->state));
+		goto done;
+	}
+
+	if (ftdmchan->state != FTDM_CHANNEL_STATE_DOWN) {
+		ftdm_log_chan(ftdmchan, FTDM_LOG_ERROR, "Cannot place call in channel in state %s!\n", ftdm_channel_state2str(ftdmchan->state));
+		goto done;
+	}
+
+	status = ftdmchan->span->outgoing_call(ftdmchan);
+	if (status == FTDM_BREAK) {
+		/* the signaling module detected glare on time */
+		ftdm_log_chan_msg(ftdmchan, FTDM_LOG_WARNING, "Glare detected, you should hunt in another channel!\n");
+		goto done;
+	}
+	
+	if (status != FTDM_SUCCESS) {
+		ftdm_log_chan_msg(ftdmchan, FTDM_LOG_ERROR, "Failed to place call!\n");
+		goto done;
+	}
+
+	/* in case of success, *before* unlocking the channel, we must set the call started flag and the call id 
+	 * that is a guarantee that signaling modules expect from us */
+	ftdm_set_flag(ftdmchan, FTDM_CHANNEL_CALL_STARTED);
+	ftdm_call_set_call_id(ftdmchan, &ftdmchan->caller_data);
+	if (!ftdm_test_flag(ftdmchan, FTDM_CHANNEL_NONBLOCK)) {
+		/* be aware this waiting unlocks the channel and locks it back when done */
 		ftdm_wait_for_flag_cleared(ftdmchan, FTDM_CHANNEL_STATE_CHANGE, 100);
 	}
 
+done:
 	ftdm_channel_unlock(ftdmchan);
 
 #ifdef __WINDOWS__
@@ -5355,7 +5397,10 @@ static void execute_safety_hangup(void *data)
 FT_DECLARE(ftdm_status_t) ftdm_span_send_signal(ftdm_span_t *span, ftdm_sigmsg_t *sigmsg)
 {
 	if (sigmsg->channel) {
-		ftdm_mutex_lock(sigmsg->channel->mutex);		
+		ftdm_mutex_lock(sigmsg->channel->mutex);
+		sigmsg->chan_id = sigmsg->channel->chan_id;
+		sigmsg->span_id = sigmsg->channel->span_id;
+		sigmsg->call_id = sigmsg->channel->caller_data.call_id;
 	}
 	
 	/* some core things to do on special events */
@@ -5373,6 +5418,12 @@ FT_DECLARE(ftdm_status_t) ftdm_span_send_signal(ftdm_span_t *span, ftdm_sigmsg_t
 
 	case FTDM_SIGEVENT_START:
 		{
+			ftdm_assert(!ftdm_test_flag(sigmsg->channel, FTDM_CHANNEL_CALL_STARTED), "Started call twice!");
+
+			if (ftdm_test_flag(sigmsg->channel, FTDM_CHANNEL_OUTBOUND)) {
+				ftdm_log_chan_msg(sigmsg->channel, FTDM_LOG_WARNING, "Inbound call taking over outbound channel\n");
+				ftdm_clear_flag(sigmsg->channel, FTDM_CHANNEL_OUTBOUND);
+			}
 			ftdm_set_flag(sigmsg->channel, FTDM_CHANNEL_CALL_STARTED);
 			ftdm_call_set_call_id(sigmsg->channel, &sigmsg->channel->caller_data);
 			ftdm_set_echocancel_call_begin(sigmsg->channel);
@@ -5410,9 +5461,6 @@ FT_DECLARE(ftdm_status_t) ftdm_span_send_signal(ftdm_span_t *span, ftdm_sigmsg_t
 
 	}
 
-	if (sigmsg->channel) {
-		sigmsg->call_id = sigmsg->channel->caller_data.call_id;
-	}
 	/* if the signaling module uses a queue for signaling notifications, then enqueue it */
 	if (ftdm_test_flag(span, FTDM_SPAN_USE_SIGNALS_QUEUE)) {
 		ftdm_span_queue_signal(span, sigmsg);

libs/freetdm/src/ftdm_state.c

@@ -164,6 +164,59 @@ static int ftdm_parse_state_map(ftdm_channel_t *ftdmchan, ftdm_channel_state_t s
 	return ok;
 }
 
+FT_DECLARE(ftdm_status_t) ftdm_channel_cancel_state(const char *file, const char *func, int line, ftdm_channel_t *fchan)
+{
+	ftdm_time_t diff;
+	ftdm_channel_state_t state;
+	ftdm_channel_state_t last_state;
+	uint8_t hindex = 0;
+
+	if (!ftdm_test_flag(fchan, FTDM_CHANNEL_STATE_CHANGE)) {
+		ftdm_log_chan(fchan, FTDM_LOG_WARNING, "Cannot cancel state change from %s to %s, it was already processed\n", 
+				ftdm_channel_state2str(fchan->last_state), ftdm_channel_state2str(fchan->state));
+		return FTDM_FAIL;
+	}
+
+	if (fchan->state_status != FTDM_STATE_STATUS_NEW) {
+		ftdm_log_chan(fchan, FTDM_LOG_WARNING, "Failed to cancel state change from %s to %s, state is not new anymore\n", 
+				ftdm_channel_state2str(fchan->last_state), ftdm_channel_state2str(fchan->state));
+		return FTDM_FAIL;
+	}
+
+	/* compute the last history index */
+	hindex = (fchan->hindex == 0) ? (ftdm_array_len(fchan->history) - 1) : (fchan->hindex - 1);
+	diff = fchan->history[hindex].end_time - fchan->history[hindex].time;
+
+	/* go back in time and revert the state to the previous state */
+	state = fchan->state;
+	last_state = fchan->last_state;
+
+	fchan->state = fchan->last_state;
+	fchan->state_status = FTDM_STATE_STATUS_COMPLETED;
+	fchan->last_state = fchan->history[hindex].last_state;
+	fchan->hindex = hindex;
+
+	/* clear the state change flag */
+	ftdm_clear_flag(fchan, FTDM_CHANNEL_STATE_CHANGE);
+
+	/* ack any pending indications as cancelled */
+	ftdm_ack_indication(fchan, fchan->indication, FTDM_ECANCELED);
+
+	/* wake up anyone sleeping waiting for the state change to complete, it won't ever be completed */
+	if (ftdm_test_flag(fchan, FTDM_CHANNEL_BLOCKING)) {
+		ftdm_clear_flag(fchan, FTDM_CHANNEL_BLOCKING);
+		ftdm_interrupt_signal(fchan->state_completed_interrupt);
+	}
+
+	/* NOTE
+	 * we could potentially also take out the channel from the pendingchans queue, but I believe is easier just leave it,
+	 * the only side effect will be a call to ftdm_channel_advance_states() for a channel that has nothing to advance */
+	ftdm_log_chan_ex(fchan, file, func, line, FTDM_LOG_LEVEL_DEBUG, "Cancelled state change from %s to %s in %llums\n", 
+			ftdm_channel_state2str(last_state), ftdm_channel_state2str(state), diff);
+	
+	return FTDM_SUCCESS;
+}
+
 /* this function MUST be called with the channel lock held. If waitrq == 1, the channel will be unlocked/locked (never call it with waitrq == 1 with an lock recursivity > 1) */
 #define DEFAULT_WAIT_TIME 1000
 FT_DECLARE(ftdm_status_t) ftdm_channel_set_state(const char *file, const char *func, int line, ftdm_channel_t *ftdmchan, ftdm_channel_state_t state, int waitrq)

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

@@ -71,7 +71,6 @@ typedef struct ftdm_r2_call_t {
 	int accepted:1;
 	int answer_pending:1;
 	int disconnect_rcvd:1;
-	int ftdm_call_started:1;
 	int protocol_error:1;
 	ftdm_size_t dnis_index;
 	ftdm_size_t ani_index;
@@ -293,6 +292,9 @@ static ftdm_call_cause_t ftdm_r2_cause_to_ftdm_cause(ftdm_channel_t *fchan, open
 
 	case OR2_CAUSE_FORCED_RELEASE:
 		return FTDM_CAUSE_NORMAL_CLEARING;
+
+	case OR2_CAUSE_GLARE:
+		return FTDM_CAUSE_REQUESTED_CHAN_UNAVAIL;
 	}
 	ftdm_log_chan(fchan, FTDM_LOG_WARNING, "Mapping openr2 cause %d to unspecified\n", cause);
 	return FTDM_CAUSE_NORMAL_UNSPECIFIED;
@@ -345,7 +347,6 @@ static void ft_r2_clean_call(ftdm_r2_call_t *call)
 	call->accepted = 0;
 	call->answer_pending = 0;
 	call->disconnect_rcvd = 0;
-	call->ftdm_call_started = 0;
 	call->protocol_error = 0;
 	call->dnis_index = 0;
 	call->ani_index = 0;
@@ -443,13 +444,6 @@ static FIO_CHANNEL_OUTGOING_CALL_FUNCTION(r2_outgoing_call)
 
 	r2data = ftdmchan->span->signal_data;
 
-	if (ftdmchan->state != FTDM_CHANNEL_STATE_DOWN) {
-		/* collision, an incoming seized the channel between our take and use timing */
-		ftdm_log_chan(ftdmchan, 
-		FTDM_LOG_CRIT, "R2 cannot dial out in channel in state %s, try another channel!.\n", ftdm_channel_state2str(ftdmchan->state));
-		return FTDM_FAIL;
-	}
-
 	ft_r2_clean_call(ftdmchan->call_data);
 
 	if (ftdmchan->caller_data.cpc == FTDM_CPC_INVALID || ftdmchan->caller_data.cpc == FTDM_CPC_UNKNOWN) {
@@ -475,7 +469,6 @@ static FIO_CHANNEL_OUTGOING_CALL_FUNCTION(r2_outgoing_call)
 		return FTDM_FAIL;
 	}
 
-	R2CALL(ftdmchan)->ftdm_call_started = 1;
 	ftdm_set_state(ftdmchan, FTDM_CHANNEL_STATE_DIALING);
 
 	ftdm_channel_set_feature(ftdmchan, FTDM_CHANNEL_FEATURE_IO_STATS);
@@ -625,7 +618,23 @@ static void ftdm_r2_on_call_init(openr2_chan_t *r2chan)
 	}
 
 	if (ftdm_test_flag(ftdmchan, FTDM_CHANNEL_INUSE)) {
-		ftdm_log_chan(ftdmchan, FTDM_LOG_CRIT, "Cannot start call when channel is in use (state = %s)\n", ftdm_channel_state2str(ftdmchan->state));
+		if (ftdmchan->state == FTDM_CHANNEL_STATE_DOWN && ftdm_test_flag(ftdmchan, FTDM_CHANNEL_OUTBOUND)) {
+			if (!ftdm_test_flag(ftdmchan, FTDM_CHANNEL_CALL_STARTED)) {
+				/* The user requested this channel but has not yet placed a call on it, we can take it over
+				 * and the user will receive FTDM_BREAK if attempts to place a call in the channel
+				 * informing him that the channel was taken over by an incoming call, although he may know
+				 * that already anyways since we sent a SIGEVENT_START on the channel */
+				ftdm_clear_flag(ftdmchan, FTDM_CHANNEL_OUTBOUND);
+			} else {
+				/* The user requested the channel and placed the call, apparently openr2 could not detect the
+				 * glare on time, but this should not happen with our locking/thread model since we always
+				 * check for state changes before processing network events (like CAS change) therefore
+				 * openr2 should at this time be aware of the call that we placed on this channel and should
+				 * have initiated the release of the call per ITU R2 spec */
+			}
+		} else {
+			ftdm_log_chan(ftdmchan, FTDM_LOG_CRIT, "Cannot start call when channel is in use (state = %s)\n", ftdm_channel_state2str(ftdmchan->state));
+		}
 		return;
 	}
 
@@ -1007,8 +1016,19 @@ static void ftdm_r2_on_call_log_created(openr2_chan_t *r2chan, const char *logna
 	snprintf(r2call->logname, sizeof(r2call->logname), "%s", logname);
 }
 
+static void ftdm_r2_on_call_proceed(openr2_chan_t *r2chan)
+{
+	ftdm_sigmsg_t sigev;
+	ftdm_channel_t *fchan = openr2_chan_get_client_data(r2chan);
+	memset(&sigev, 0, sizeof(sigev));
+	sigev.event_id = FTDM_SIGEVENT_PROCEED;
+	sigev.channel = fchan;
+	ftdm_span_send_signal(fchan->span, &sigev);
+}
+
 static openr2_event_interface_t ftdm_r2_event_iface = {
 	/* .on_call_init */ ftdm_r2_on_call_init,
+	/* .on_call_proceed */ ftdm_r2_on_call_proceed,
 	/* .on_call_offered */ ftdm_r2_on_call_offered,
 	/* .on_call_accepted */ ftdm_r2_on_call_accepted,
 	/* .on_call_answered */ ftdm_r2_on_call_answered,
@@ -1691,8 +1711,7 @@ static ftdm_status_t ftdm_r2_state_advance(ftdm_channel_t *ftdmchan)
 				uint32_t interval = 0;
 				ftdm_channel_command(ftdmchan, FTDM_COMMAND_GET_INTERVAL, &interval);
 				ftdm_assert(interval != 0, "Invalid interval!");
-				ftdm_log_chan(ftdmchan, 
+				ftdm_log_chan(ftdmchan, FTDM_LOG_DEBUG, "Starting outgoing call with interval %d\n", interval);
-					FTDM_LOG_DEBUG, "Starting processing of outgoing call in channel with interval %d\n", interval);
 				openr2_chan_enable_read(r2chan);
 			}
 			break;
@@ -1702,10 +1721,7 @@ static ftdm_status_t ftdm_r2_state_advance(ftdm_channel_t *ftdmchan)
 
 			/* notify the user about the new call */
 			sigev.event_id = FTDM_SIGEVENT_START;
-
 			ftdm_span_send_signal(ftdmchan->span, &sigev);
-			r2call->ftdm_call_started = 1; 
-
 			break;
 
 			/* the call is making progress */
@@ -1719,9 +1735,6 @@ static ftdm_status_t ftdm_r2_state_advance(ftdm_channel_t *ftdmchan)
 					} 
 				} else {
 					ftdm_log_chan_msg(ftdmchan, FTDM_LOG_DEBUG, "Notifying progress\n");
-					sigev.event_id = FTDM_SIGEVENT_PROCEED;
-					ftdm_span_send_signal(ftdmchan->span, &sigev);
-
 					sigev.event_id = FTDM_SIGEVENT_PROGRESS_MEDIA;
 					ftdm_span_send_signal(ftdmchan->span, &sigev);
 				}
@@ -1772,7 +1785,7 @@ static ftdm_status_t ftdm_r2_state_advance(ftdm_channel_t *ftdmchan)
 		case FTDM_CHANNEL_STATE_TERMINATING:
 			{
 				/* if the call has not been started yet we must go to HANGUP right here */ 
-				if (!r2call->ftdm_call_started) {
+				if (!ftdm_test_flag(ftdmchan, FTDM_CHANNEL_CALL_STARTED)) {
 					ftdm_set_state(ftdmchan, FTDM_CHANNEL_STATE_HANGUP);
 				} else {
 					openr2_call_disconnect_cause_t disconnect_cause = ftdm_r2_ftdm_cause_to_openr2_cause(ftdmchan);

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

@@ -177,6 +177,12 @@ struct ftdm_state_map {
 };
 typedef struct ftdm_state_map ftdm_state_map_t;
 
+/*!\brief Cancel the state processing for a channel (the channel must be locked when calling this function)
+ * \note Only the core should use this function
+ */ 
+FT_DECLARE(ftdm_status_t) ftdm_channel_cancel_state(const char *file, const char *func, int line,
+		ftdm_channel_t *ftdmchan);
+
 /*!\brief Set the state for a channel (the channel must be locked when calling this function)
  * \note Signaling modules should use ftdm_set_state macro instead
  * \note If this function is called with the wait parameter set to a non-zero value, the recursivity