Merge branch 'master' into moy.iodump

libs/freetdm/freetdm.2008.sln

@@ -64,6 +64,9 @@ Project("{8BC9CEB8-8B4A-11D0-8D11-00A0C91BC942}") = "ftmod_sangoma_isdn", "src\f
 	EndProjectSection
 EndProject
 Project("{8BC9CEB8-8B4A-11D0-8D11-00A0C91BC942}") = "ftmod_r2", "src\ftmod\ftmod_r2\ftmod_r2.2008.vcproj", "{08C3EA27-A51D-47F8-B47D-B189C649CF30}"
+	ProjectSection(ProjectDependencies) = postProject
+		{93B8812C-3EC4-4F78-8970-FFBFC99E167D} = {93B8812C-3EC4-4F78-8970-FFBFC99E167D}
+	EndProjectSection
 EndProject
 Global
 	GlobalSection(SolutionConfigurationPlatforms) = preSolution
@@ -131,7 +134,6 @@ Global
 		{1A145EE9-BBD8-45E5-98CD-EB4BE99E1DCD}.Release|Win32.ActiveCfg = Release|Win32
 		{1A145EE9-BBD8-45E5-98CD-EB4BE99E1DCD}.Release|x64.ActiveCfg = Release|x64
 		{D021EF2A-460D-4827-A0F7-41FDECF46F1B}.Debug|Win32.ActiveCfg = Debug|Win32
-		{D021EF2A-460D-4827-A0F7-41FDECF46F1B}.Debug|Win32.Build.0 = Debug|Win32
 		{D021EF2A-460D-4827-A0F7-41FDECF46F1B}.Debug|x64.ActiveCfg = Debug|x64
 		{D021EF2A-460D-4827-A0F7-41FDECF46F1B}.Debug|x64.Build.0 = Debug|x64
 		{D021EF2A-460D-4827-A0F7-41FDECF46F1B}.Release|Win32.ActiveCfg = Release|Win32
@@ -139,7 +141,6 @@ Global
 		{D021EF2A-460D-4827-A0F7-41FDECF46F1B}.Release|x64.ActiveCfg = Release|x64
 		{D021EF2A-460D-4827-A0F7-41FDECF46F1B}.Release|x64.Build.0 = Release|x64
 		{2B1BAF36-0241-43E7-B865-A8338AD48E2E}.Debug|Win32.ActiveCfg = Debug|Win32
-		{2B1BAF36-0241-43E7-B865-A8338AD48E2E}.Debug|Win32.Build.0 = Debug|Win32
 		{2B1BAF36-0241-43E7-B865-A8338AD48E2E}.Debug|x64.ActiveCfg = Debug|x64
 		{2B1BAF36-0241-43E7-B865-A8338AD48E2E}.Debug|x64.Build.0 = Debug|x64
 		{2B1BAF36-0241-43E7-B865-A8338AD48E2E}.Release|Win32.ActiveCfg = Release|Win32
@@ -147,7 +148,6 @@ Global
 		{2B1BAF36-0241-43E7-B865-A8338AD48E2E}.Release|x64.ActiveCfg = Release|x64
 		{2B1BAF36-0241-43E7-B865-A8338AD48E2E}.Release|x64.Build.0 = Release|x64
 		{0DA69C18-4FA1-4E8C-89CE-12498637C5BE}.Debug|Win32.ActiveCfg = Debug|Win32
-		{0DA69C18-4FA1-4E8C-89CE-12498637C5BE}.Debug|Win32.Build.0 = Debug|Win32
 		{0DA69C18-4FA1-4E8C-89CE-12498637C5BE}.Debug|x64.ActiveCfg = Debug|x64
 		{0DA69C18-4FA1-4E8C-89CE-12498637C5BE}.Debug|x64.Build.0 = Debug|x64
 		{0DA69C18-4FA1-4E8C-89CE-12498637C5BE}.Release|Win32.ActiveCfg = Release|Win32
@@ -155,13 +155,11 @@ Global
 		{0DA69C18-4FA1-4E8C-89CE-12498637C5BE}.Release|x64.ActiveCfg = Release|x64
 		{0DA69C18-4FA1-4E8C-89CE-12498637C5BE}.Release|x64.Build.0 = Release|x64
 		{B2AF4EA6-0CD7-4529-9EB5-5AF43DB90395}.Debug|Win32.ActiveCfg = Debug|Win32
-		{B2AF4EA6-0CD7-4529-9EB5-5AF43DB90395}.Debug|Win32.Build.0 = Debug|Win32
 		{B2AF4EA6-0CD7-4529-9EB5-5AF43DB90395}.Debug|x64.ActiveCfg = Debug|Win32
 		{B2AF4EA6-0CD7-4529-9EB5-5AF43DB90395}.Release|Win32.ActiveCfg = Release|Win32
 		{B2AF4EA6-0CD7-4529-9EB5-5AF43DB90395}.Release|Win32.Build.0 = Release|Win32
 		{B2AF4EA6-0CD7-4529-9EB5-5AF43DB90395}.Release|x64.ActiveCfg = Release|Win32
 		{08C3EA27-A51D-47F8-B47D-B189C649CF30}.Debug|Win32.ActiveCfg = Debug|Win32
-		{08C3EA27-A51D-47F8-B47D-B189C649CF30}.Debug|Win32.Build.0 = Debug|Win32
 		{08C3EA27-A51D-47F8-B47D-B189C649CF30}.Debug|x64.ActiveCfg = Debug|Win32
 		{08C3EA27-A51D-47F8-B47D-B189C649CF30}.Release|Win32.ActiveCfg = Release|Win32
 		{08C3EA27-A51D-47F8-B47D-B189C649CF30}.Release|Win32.Build.0 = Release|Win32

libs/freetdm/mod_freetdm/mod_freetdm.c

@@ -3234,33 +3234,10 @@ static switch_status_t load_config(void)
 
 	if ((spans = switch_xml_child(cfg, "r2_spans"))) {
 		for (myspan = switch_xml_child(spans, "span"); myspan; myspan = myspan->next) {
-			char *id = (char *) switch_xml_attr(myspan, "id");
 			char *name = (char *) switch_xml_attr(myspan, "name");
+			char *configname = (char *) switch_xml_attr(myspan, "cfgprofile");
 			ftdm_status_t zstatus = FTDM_FAIL;
 
-			/* strings */
-			const char *variant = "itu";
-			const char *category = "national_subscriber";
-			const char *logdir = "/usr/local/freeswitch/log/"; /* FIXME: get PREFIX variable */
-			const char *logging = "notice,warning,error";
-			const char *advanced_protocol_file = "";
-
-			/* booleans */
-			int call_files = 0;
-			int get_ani_first = -1;
-			int immediate_accept = -1;
-			int double_answer = -1;
-			int skip_category = -1;
-			int forced_release = -1;
-			int charge_calls = -1;
-
-			/* integers */
-			int mfback_timeout = -1;
-			int metering_pulse_timeout = -1;
-			int allow_collect_calls = -1;
-			int max_ani = 10;
-			int max_dnis = 4;
-
 			/* common non r2 stuff */
 			const char *context = "default";
 			const char *dialplan = "XML";
@@ -3269,53 +3246,29 @@ static switch_status_t load_config(void)
 			uint32_t span_id = 0;
 			ftdm_span_t *span = NULL;
 
+			ftdm_conf_parameter_t spanparameters[30];
+			unsigned paramindex = 0;
+
+			if (!name) {
+				switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "'name' attribute required for R2 spans!\n");
+				continue;
+			}
+
+			memset(spanparameters, 0, sizeof(spanparameters));
+
+			if (configname) {
+				paramindex = add_profile_parameters(cfg, configname, spanparameters, ftdm_array_len(spanparameters));
+				if (paramindex) {
+					ftdm_log(FTDM_LOG_DEBUG, "Added %d parameters from profile %s for span %d\n", paramindex, configname, span_id);
+				}
+			}
 
 			for (param = switch_xml_child(myspan, "param"); param; param = param->next) {
 				char *var = (char *) switch_xml_attr_soft(param, "name");
 				char *val = (char *) switch_xml_attr_soft(param, "value");
 
 				/* string parameters */
-				if (!strcasecmp(var, "variant")) {
-					variant = val;
-				} else if (!strcasecmp(var, "category")) {
-					category = val;
-				} else if (!strcasecmp(var, "logdir")) {
-					logdir = val;
-				} else if (!strcasecmp(var, "logging")) {
-					logging = val;
-				} else if (!strcasecmp(var, "advanced_protocol_file")) {
-					advanced_protocol_file = val;
-
-				/* booleans */
-				} else if (!strcasecmp(var, "allow_collect_calls")) {
-					allow_collect_calls = switch_true(val);
-				} else if (!strcasecmp(var, "immediate_accept")) {
-					immediate_accept = switch_true(val);
-				} else if (!strcasecmp(var, "double_answer")) {
-					double_answer = switch_true(val);
-				} else if (!strcasecmp(var, "skip_category")) {
-					skip_category = switch_true(var);
-				} else if (!strcasecmp(var, "forced_release")) {
-					forced_release = switch_true(val);
-				} else if (!strcasecmp(var, "charge_calls")) {
-					charge_calls = switch_true(val);
-				} else if (!strcasecmp(var, "get_ani_first")) {
-					get_ani_first = switch_true(val);
-				} else if (!strcasecmp(var, "call_files")) {
-					call_files = switch_true(val);
-
-				/* integers */
-				} else if (!strcasecmp(var, "mfback_timeout")) {
-					mfback_timeout = atoi(val);
-				} else if (!strcasecmp(var, "metering_pulse_timeout")) {
-					metering_pulse_timeout = atoi(val);
-				} else if (!strcasecmp(var, "max_ani")) {
-					max_ani = atoi(val);
-				} else if (!strcasecmp(var, "max_dnis")) {
-					max_dnis = atoi(val);
-
-				/* common non r2 stuff */
-				} else if (!strcasecmp(var, "context")) {
+				if (!strcasecmp(var, "context")) {
 					context = val;
 				} else if (!strcasecmp(var, "dialplan")) {
 					dialplan = val;
@@ -3323,57 +3276,23 @@ static switch_status_t load_config(void)
 					dial_regex = val;
 				} else if (!strcasecmp(var, "fail-dial-regex")) {
 					fail_dial_regex = val;
+				} else {
+					spanparameters[paramindex].var = var;
+					spanparameters[paramindex].val = val;
+					paramindex++;
 				}
 			}
 
-			if (!id && !name) {
-				switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "span missing required param 'id'\n");
-				continue;
-			}
-
-			if (name) {
-				zstatus = ftdm_span_find_by_name(name, &span);
-			} else {
-				if (switch_is_number(id)) {
-					span_id = atoi(id);
-					zstatus = ftdm_span_find(span_id, &span);
-				}
-
-				if (zstatus != FTDM_SUCCESS) {
-					zstatus = ftdm_span_find_by_name(id, &span);
-				}
-			}
-
+			zstatus = ftdm_span_find_by_name(name, &span);
 			if (zstatus != FTDM_SUCCESS) {
-				ftdm_log(FTDM_LOG_ERROR, "Error finding FreeTDM span id:%s name:%s\n", switch_str_nil(id), switch_str_nil(name));
+				ftdm_log(FTDM_LOG_ERROR, "Error finding FreeTDM R2 Span '%s'\n", name);
 				continue;
 			}
+			span_id = ftdm_span_get_id(span);
 
-			if (!span_id) {
-				span_id = ftdm_span_get_id(span);
-			}
-
-			if (ftdm_configure_span(span, "r2", on_r2_signal, 
-				"variant", variant, 
-				"max_ani", max_ani,
-				"max_dnis", max_dnis,
-				"category", category,
-				"logdir", logdir,
-				"logging", logging,
-				"advanced_protocol_file", advanced_protocol_file,
-				"allow_collect_calls", allow_collect_calls,
-				"immediate_accept", immediate_accept,
-				"double_answer", double_answer,
-				"skip_category", skip_category,
-				"forced_release", forced_release,
-				"charge_calls", charge_calls,
-				"get_ani_first", get_ani_first,
-				"call_files", call_files,
-				"mfback_timeout", mfback_timeout,
-				"metering_pulse_timeout", metering_pulse_timeout, 
-				FTDM_TAG_END) != FTDM_SUCCESS) {
-				ftdm_log(FTDM_LOG_ERROR, "Error configuring R2 FreeTDM span %d, error: %s\n", 
-				span_id, ftdm_span_get_last_error(span));
+			if (ftdm_configure_span_signaling(span, "r2", on_r2_signal, spanparameters) != FTDM_SUCCESS) {
+				ftdm_log(FTDM_LOG_ERROR, "Error configuring FreeTDM R2 span %s, error: %s\n", 
+				name, ftdm_span_get_last_error(span));
 				continue;
 			}
 
@@ -3388,10 +3307,10 @@ static switch_status_t load_config(void)
 			SPAN_CONFIG[span_id].span = span;
 			switch_copy_string(SPAN_CONFIG[span_id].context, context, sizeof(SPAN_CONFIG[span_id].context));
 			switch_copy_string(SPAN_CONFIG[span_id].dialplan, dialplan, sizeof(SPAN_CONFIG[span_id].dialplan));
-			switch_copy_string(SPAN_CONFIG[span_id].type, "r2", sizeof(SPAN_CONFIG[span_id].type));
+			switch_copy_string(SPAN_CONFIG[span_id].type, "R2", sizeof(SPAN_CONFIG[span_id].type));
 
 			if (ftdm_span_start(span) == FTDM_FAIL) {
-				ftdm_log(FTDM_LOG_ERROR, "Error starting R2 FreeTDM span %d, error: %s\n", span_id, ftdm_span_get_last_error(span));
+				ftdm_log(FTDM_LOG_ERROR, "Error starting FreeTDM R2 span %s, error: %s\n", name, ftdm_span_get_last_error(span));
 				continue;
 			}
 		}

libs/freetdm/src/ftdm_io.c

@@ -1101,6 +1101,51 @@ FT_DECLARE(ftdm_status_t) ftdm_span_next_event(ftdm_span_t *span, ftdm_event_t *
 	return status;
 }
 
+FT_DECLARE(ftdm_status_t) ftdm_channel_read_event(ftdm_channel_t *ftdmchan, ftdm_event_t **event)
+{
+	ftdm_status_t status = FTDM_FAIL;
+	ftdm_sigmsg_t sigmsg;
+	ftdm_span_t *span = ftdmchan->span;
+	ftdm_assert_return(span->fio != NULL, FTDM_FAIL, "No I/O module attached to this span!\n");
+
+	if (!span->fio->channel_next_event) {
+		ftdm_log(FTDM_LOG_ERROR, "channel_next_event method not implemented in module %s!", span->fio->name);
+		return FTDM_NOTIMPL;
+	}
+
+	status = span->fio->channel_next_event(ftdmchan, event);
+	if (status != FTDM_SUCCESS) {
+		return status;
+	}
+
+	/* before returning the event to the user we do some core operations with certain OOB events */
+	memset(&sigmsg, 0, sizeof(sigmsg));
+	sigmsg.span_id = span->span_id;
+	sigmsg.chan_id = (*event)->channel->chan_id;
+	sigmsg.channel = (*event)->channel;
+	switch ((*event)->enum_id) {
+	case FTDM_OOB_ALARM_CLEAR:
+		{
+			sigmsg.event_id = FTDM_SIGEVENT_ALARM_CLEAR;
+			ftdm_clear_flag_locked((*event)->channel, FTDM_CHANNEL_IN_ALARM);
+			ftdm_span_send_signal(span, &sigmsg);
+		}
+		break;
+	case FTDM_OOB_ALARM_TRAP:
+		{
+			sigmsg.event_id = FTDM_SIGEVENT_ALARM_TRAP;
+			ftdm_set_flag_locked((*event)->channel, FTDM_CHANNEL_IN_ALARM);
+			ftdm_span_send_signal(span, &sigmsg);
+		}
+		break;
+	default:
+		/* NOOP */
+		break;
+	}
+
+	return status;
+}
+
 static ftdm_status_t ftdmchan_fsk_write_sample(int16_t *buf, ftdm_size_t buflen, void *user_data)
 {
 	ftdm_channel_t *ftdmchan = (ftdm_channel_t *) user_data;

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

@@ -56,21 +56,15 @@ typedef enum {
 	FTDM_R2_RUNNING = (1 << 0),
 } ftdm_r2_flag_t;
 
-typedef enum {
-	FTDM_R2_PROCESSING = (1 << 0),
-	FTDM_R2_WAITING_ACK = (1 << 1),
-} ftdm_r2_call_flag_t;
-
 /* private call information stored in ftdmchan->call_data void* ptr */
 #define R2CALL(ftdmchan) ((ftdm_r2_call_t*)((ftdmchan)->call_data))
 typedef struct ftdm_r2_call_t {
 	openr2_chan_t *r2chan;
-	ftdm_r2_call_flag_t flags;
 	int accepted:1;
 	int answer_pending:1;
-	int state_ack_pending:1;
 	int disconnect_rcvd:1;
-	int ftdm_started:1;
+	int ftdm_call_started:1;
+	int protocol_error:1;
 	ftdm_channel_state_t chanstate;
 	ftdm_size_t dnis_index;
 	ftdm_size_t ani_index;
@@ -124,11 +118,13 @@ typedef struct ftdm_r2_data_s {
 	/* whether accept the call when offered, or wait until the user decides to accept */
 	int accept_on_offer:1;
 	/* max time spent in ms doing real work in a single loop */
-	int jobmax;
-	/* total working loops */
-	unsigned long loops;
+	int32_t jobmax;
+	/* Total number of loops performed so far */
+	uint64_t total_loops;
+	/* number of loops per 10ms increment from 0-9ms, 10-19ms .. 100ms and above */
+	uint64_t loops[11];
 	/* LWP */
-	unsigned long monitor_thread_id;
+	uint32_t monitor_thread_id;
 } ftdm_r2_data_t;
 
 /* one element per span will be stored in g_mod_data_hash global var to keep track of them
@@ -151,7 +147,14 @@ static ftdm_hash_t *g_mod_data_hash;
 static ftdm_io_interface_t g_ftdm_r2_interface;
 
 static int ftdm_r2_state_advance(ftdm_channel_t *ftdmchan);
+static void ftdm_r2_state_advance_all(ftdm_channel_t *ftdmchan);
 
+/* whether R2 call accept process is pending */
+#define IS_ACCEPTING_PENDING(ftdmchan) \
+		( (!ftdm_test_flag((ftdmchan), FTDM_CHANNEL_OUTBOUND)) && !R2CALL((ftdmchan))->accepted && \
+				((ftdmchan)->state == FTDM_CHANNEL_STATE_PROGRESS || \
+				 (ftdmchan)->state == FTDM_CHANNEL_STATE_PROGRESS_MEDIA || \
+				 (ftdmchan)->state == FTDM_CHANNEL_STATE_UP) )
 
 /* functions not available on windows */
 #ifdef WIN32
@@ -313,9 +316,9 @@ static openr2_call_disconnect_cause_t ftdm_r2_ftdm_cause_to_openr2_cause(ftdm_ch
 
 static void ft_r2_clean_call(ftdm_r2_call_t *call)
 {
-    openr2_chan_t *r2chan = call->r2chan;
-    memset(call, 0, sizeof(*call));
-    call->r2chan = r2chan;
+	openr2_chan_t *r2chan = call->r2chan;
+	memset(call, 0, sizeof(*call));
+	call->r2chan = r2chan;
 }
 
 static void ft_r2_accept_call(ftdm_channel_t *ftdmchan)
@@ -355,30 +358,26 @@ static FIO_CHANNEL_OUTGOING_CALL_FUNCTION(r2_outgoing_call)
 	}
 
 	ft_r2_clean_call(ftdmchan->call_data);
-	R2CALL(ftdmchan)->ftdm_started = 1;
+	R2CALL(ftdmchan)->ftdm_call_started = 1;
 	R2CALL(ftdmchan)->chanstate = FTDM_CHANNEL_STATE_DOWN;
-    ftdm_set_state(ftdmchan, FTDM_CHANNEL_STATE_DIALING);
+	ftdm_set_state(ftdmchan, FTDM_CHANNEL_STATE_DIALING);
 
 	callstatus = openr2_chan_make_call(R2CALL(ftdmchan)->r2chan, 
 			ftdmchan->caller_data.cid_num.digits, 
 			ftdmchan->caller_data.dnis.digits, 
 			OR2_CALLING_PARTY_CATEGORY_NATIONAL_SUBSCRIBER);
 
-    if (callstatus) {
-        ftdm_log_chan_msg(ftdmchan, FTDM_LOG_CRIT, "Failed to make call in R2 channel, openr2_chan_make_call failed\n");
-        return FTDM_FAIL;
-    }
+	if (callstatus) {
+		ftdm_log_chan_msg(ftdmchan, FTDM_LOG_CRIT, "Failed to make call in R2 channel, openr2_chan_make_call failed\n");
+		return FTDM_FAIL;
+	}
 
 	if (ftdmchan->state !=  FTDM_CHANNEL_STATE_DIALING) {
 		ftdm_log_chan(ftdmchan, FTDM_LOG_WARNING, "Collision after call attempt, try another channel, new state = %s\n",
 				ftdm_channel_state2str(ftdmchan->state));
-		ftdm_clear_flag(R2CALL(ftdmchan), FTDM_R2_WAITING_ACK);
 		return FTDM_BREAK;
 	}
-
-    /* non-threaded implementation, we're done here */
-    ftdm_log_chan_msg(ftdmchan, FTDM_LOG_DEBUG, "R2 call placed in non-threaded mode\n");
-    return FTDM_SUCCESS;
+	return FTDM_SUCCESS;
 }
 
 static ftdm_status_t ftdm_r2_start(ftdm_span_t *span)
@@ -398,44 +397,26 @@ static ftdm_status_t ftdm_r2_stop(ftdm_span_t *span)
 	return FTDM_SUCCESS;
 }
 
-static ftdm_status_t ftdm_r2_sig_read(ftdm_channel_t *ftdmchan, void *data, ftdm_size_t size)
-{
-	openr2_chan_t *r2chan = R2CALL(ftdmchan)->r2chan;
-	if (!openr2_chan_get_read_enabled(r2chan)) {
-		ftdm_mutex_lock(ftdmchan->mutex);
-		//openr2_chan_process_input(r2chan, data, size);
-		ftdm_mutex_unlock(ftdmchan->mutex);
-	}
-	return FTDM_SUCCESS;
-}
-
 /* always called from the monitor thread */
 static void ftdm_r2_on_call_init(openr2_chan_t *r2chan)
 {
-	//ftdm_status_t status;
 	ftdm_r2_call_t *r2call;
 	ftdm_channel_t *ftdmchan = openr2_chan_get_client_data(r2chan);
-	//ftdm_r2_data_t *r2data = ftdmchan->span->signal_data;
 
 	ftdm_log_chan_msg(ftdmchan, FTDM_LOG_NOTICE, "Received request to start call\n");
 
-	ftdm_mutex_lock(ftdmchan->mutex);
-
 	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));
-		ftdm_mutex_unlock(ftdmchan->mutex);
 		return;
 	}
 
 	if (ftdmchan->state != FTDM_CHANNEL_STATE_DOWN) {
 		ftdm_log_chan(ftdmchan, FTDM_LOG_ERROR, "Cannot handle request to start call in state %s\n", ftdm_channel_state2str(ftdmchan->state));
-		ftdm_mutex_unlock(ftdmchan->mutex);
 		return;
 	}
 
 	if (ftdm_channel_open_chan(ftdmchan) != FTDM_SUCCESS) {
 		ftdm_log_chan(ftdmchan, FTDM_LOG_ERROR, "Failed to open channel during incoming call! [%s]\n", ftdmchan->last_error);
-		ftdm_mutex_unlock(ftdmchan->mutex);
 		return;
 	}
 
@@ -448,7 +429,6 @@ static void ftdm_r2_on_call_init(openr2_chan_t *r2chan)
 	/* clean the call data structure but keep the R2 processing flag on! */
 	ft_r2_clean_call(ftdmchan->call_data);
 	r2call = R2CALL(ftdmchan);
-	ftdm_set_flag(r2call, FTDM_R2_PROCESSING);
 
 	if (ftdmchan->state == FTDM_CHANNEL_STATE_DOWN) {
 		R2CALL(ftdmchan)->chanstate = FTDM_CHANNEL_STATE_DOWN;
@@ -457,7 +437,6 @@ static void ftdm_r2_on_call_init(openr2_chan_t *r2chan)
 	}
 
 	ftdm_set_state(ftdmchan, FTDM_CHANNEL_STATE_COLLECT);
-	ftdm_mutex_unlock(ftdmchan->mutex);
 }
 
 /* only called for incoming calls when the ANI, DNIS etc is complete and the user has to decide either to accept or reject the call */
@@ -465,26 +444,55 @@ static void ftdm_r2_on_call_offered(openr2_chan_t *r2chan, const char *ani, cons
 {
 	ftdm_channel_t *ftdmchan = openr2_chan_get_client_data(r2chan);
 
-	ftdm_log_chan(ftdmchan, FTDM_LOG_NOTICE, "Call offered with ANI = %s, DNIS = %s, Priority = (%d)\n", ani, dnis, category);
-	ftdm_set_state_locked(ftdmchan, FTDM_CHANNEL_STATE_RING);
+	ftdm_log_chan(ftdmchan, FTDM_LOG_NOTICE, "Call offered with ANI = %s, DNIS = %s, Category = (%d)\n", ani, dnis, category);
+	ftdm_set_state(ftdmchan, FTDM_CHANNEL_STATE_RING);
+}
+
+/*
+ * Accepting a call in R2 is a lengthy process due to MF tones,
+ * when the user sends PROGRESS indication (implicitly moving the
+ * ftdm channel to PROGRESS state) the R2 processing loop
+ * does not clear FTDM_CHANNEL_STATE_CHANGE immediately as it does
+ * for all the other states, instead has to wait for on_call_accepted
+ * callback from openr2, which means the MF has ended and the progress
+ * indication is done, in order to clear the flag. However, if
+ * a protocol error or call disconnection (which is indicated using CAS bits)
+ * occurrs while accepting, we must clear the pending flag, this function
+ * takes care of that
+ * */
+static void clear_accept_pending(ftdm_channel_t *fchan)
+{
+	if (IS_ACCEPTING_PENDING(fchan)) {
+		ftdm_clear_flag(fchan, FTDM_CHANNEL_STATE_CHANGE);
+		ftdm_channel_complete_state(fchan);
+	} else if (ftdm_test_flag(fchan, FTDM_CHANNEL_STATE_CHANGE)) {
+		ftdm_log_chan(fchan, FTDM_LOG_CRIT, "State change flag set in state %s, last state = %s\n", 
+				ftdm_channel_state2str(fchan->state), ftdm_channel_state2str(fchan->last_state));
+		ftdm_clear_flag(fchan, FTDM_CHANNEL_STATE_CHANGE);
+		ftdm_channel_complete_state(fchan);
+	}
 }
 
 static void ftdm_r2_on_call_accepted(openr2_chan_t *r2chan, openr2_call_mode_t mode)
 {
 	ftdm_channel_t *ftdmchan = openr2_chan_get_client_data(r2chan);
 	ftdm_log_chan_msg(ftdmchan, FTDM_LOG_NOTICE, "Call accepted\n");
+
+	clear_accept_pending(ftdmchan);
+
 	/* at this point the MF signaling has ended and there is no point on keep reading */
 	openr2_chan_disable_read(r2chan);
 	R2CALL(ftdmchan)->accepted = 1;
+
 	if (OR2_DIR_BACKWARD == openr2_chan_get_direction(r2chan)) {
-		R2CALL(ftdmchan)->state_ack_pending = 1;
 		if (R2CALL(ftdmchan)->answer_pending) {
 			ftdm_log_chan_msg(ftdmchan, FTDM_LOG_DEBUG, "Answer was pending, answering now.\n");
 			ft_r2_answer_call(ftdmchan);
+			R2CALL(ftdmchan)->answer_pending = 0;
 			return;
 		}
 	} else {
-		ftdm_set_state_locked(ftdmchan, FTDM_CHANNEL_STATE_PROGRESS_MEDIA);
+		ftdm_set_state(ftdmchan, FTDM_CHANNEL_STATE_PROGRESS_MEDIA);
 	}
 }
 
@@ -494,47 +502,30 @@ static void ftdm_r2_on_call_answered(openr2_chan_t *r2chan)
 	ftdm_log_chan_msg(ftdmchan, FTDM_LOG_NOTICE, "Call answered\n");
 	/* notify the upper layer of progress in the outbound call */
 	if (OR2_DIR_FORWARD == openr2_chan_get_direction(r2chan)) {
-		ftdm_set_state_locked(ftdmchan, FTDM_CHANNEL_STATE_UP);
+		ftdm_set_state(ftdmchan, FTDM_CHANNEL_STATE_UP);
 	}
 }
 
 /* may be called in the signaling or media thread depending on whether the hangup is product of MF or CAS signaling */
 static void ftdm_r2_on_call_disconnect(openr2_chan_t *r2chan, openr2_call_disconnect_cause_t cause)
 {
-	ftdm_sigmsg_t sigev;
-	ftdm_r2_data_t *r2data;
 	ftdm_channel_t *ftdmchan = openr2_chan_get_client_data(r2chan);
 
 	ftdm_log_chan_msg(ftdmchan, FTDM_LOG_NOTICE, "Call disconnected\n");
 
-	ftdm_log_chan_msg(ftdmchan, FTDM_LOG_DEBUG, "Got openr2 disconnection, clearing call\n");
+	clear_accept_pending(ftdmchan);
 
 	R2CALL(ftdmchan)->disconnect_rcvd = 1;
 
 	if (ftdmchan->state == FTDM_CHANNEL_STATE_HANGUP) {
 		ftdm_log_chan_msg(ftdmchan, FTDM_LOG_DEBUG, "Call had been disconnected already by the user\n");
-		/* just ack the hangup to go down */
+		/* just ack the hangup to trigger the on_call_end callback and go down */
 		openr2_chan_disconnect_call(r2chan, OR2_CAUSE_NORMAL_CLEARING);
 		return;
 	}
 
-	/* if the call has not been started yet we must go to HANGUP right here */ 
-	if (!R2CALL(ftdmchan)->ftdm_started) {
-		ftdm_set_state_locked(ftdmchan, FTDM_CHANNEL_STATE_HANGUP);
-		return;
-	}
-
 	ftdmchan->caller_data.hangup_cause  = ftdm_r2_cause_to_ftdm_cause(ftdmchan, cause);
-
-	/* notify the user of the call terminating */
-	memset(&sigev, 0, sizeof(sigev));
-	sigev.chan_id = ftdmchan->chan_id;
-	sigev.span_id = ftdmchan->span_id;
-	sigev.channel = ftdmchan;
-	sigev.event_id = FTDM_SIGEVENT_STOP;
-	r2data = ftdmchan->span->signal_data;
-
-	ftdm_span_send_signal(ftdmchan->span, &sigev);
+	ftdm_set_state(ftdmchan, FTDM_CHANNEL_STATE_TERMINATING);
 }
 
 static void ftdm_r2_on_call_end(openr2_chan_t *r2chan)
@@ -543,10 +534,10 @@ static void ftdm_r2_on_call_end(openr2_chan_t *r2chan)
 	ftdm_log_chan_msg(ftdmchan, FTDM_LOG_NOTICE, "Call finished\n");
 
 	/* the call is done as far as the stack is concerned, lets move to down here */
-	ftdm_set_state_locked(ftdmchan, FTDM_CHANNEL_STATE_DOWN);
+	ftdm_set_state(ftdmchan, FTDM_CHANNEL_STATE_DOWN);
 
 	/* in some circumstances openr2 can call on_call_init right after this, so let's advance the state right here */
-	ftdm_r2_state_advance(ftdmchan);
+	ftdm_r2_state_advance_all(ftdmchan);
 }
 
 static void ftdm_r2_on_call_read(openr2_chan_t *r2chan, const unsigned char *buf, int buflen)
@@ -570,40 +561,28 @@ static void ftdm_r2_on_os_error(openr2_chan_t *r2chan, int errorcode)
 
 static void ftdm_r2_on_protocol_error(openr2_chan_t *r2chan, openr2_protocol_error_t reason)
 {
-	ftdm_sigmsg_t sigev;
-	ftdm_r2_data_t *r2data;
 	ftdm_channel_t *ftdmchan = openr2_chan_get_client_data(r2chan);
 
-	ftdm_mutex_lock(ftdmchan->mutex);
-
 	if (ftdmchan->state == FTDM_CHANNEL_STATE_DOWN) {
 		ftdm_log_chan_msg(ftdmchan, FTDM_LOG_ERROR, "Got protocol error when we're already down!\n");
-		ftdm_mutex_unlock(ftdmchan->mutex);
+		return;
 	}
 
 	ftdm_log_chan_msg(ftdmchan, FTDM_LOG_ERROR, "Protocol error\n");
 
+	clear_accept_pending(ftdmchan);
+
 	R2CALL(ftdmchan)->disconnect_rcvd = 1;
+	R2CALL(ftdmchan)->protocol_error = 1;
 
-	if (!R2CALL(ftdmchan)->ftdm_started) {
-		ftdm_set_state(ftdmchan, FTDM_CHANNEL_STATE_HANGUP);
-		ftdm_mutex_unlock(ftdmchan->mutex);
+	if (ftdmchan->state == FTDM_CHANNEL_STATE_HANGUP) {
+		ftdm_log_chan_msg(ftdmchan, FTDM_LOG_ERROR, "The user already hung up, finishing call in protocol error\n");
+		ftdm_set_state(ftdmchan, FTDM_CHANNEL_STATE_DOWN);
 		return;
 	}
 
 	ftdmchan->caller_data.hangup_cause  = FTDM_CAUSE_PROTOCOL_ERROR; 
-
-	/* FIXME: go to terminating and notify the user from the terminating handler instead of notifying here */
-	memset(&sigev, 0, sizeof(sigev));
-	sigev.chan_id = ftdmchan->chan_id;
-	sigev.span_id = ftdmchan->span_id;
-	sigev.channel = ftdmchan;
-	sigev.event_id = FTDM_SIGEVENT_STOP;
-	r2data = ftdmchan->span->signal_data;
-
-	ftdm_span_send_signal(ftdmchan->span, &sigev);
-
-	ftdm_mutex_unlock(ftdmchan->mutex);
+	ftdm_set_state(ftdmchan, FTDM_CHANNEL_STATE_TERMINATING);
 }
 
 static void ftdm_r2_on_line_blocked(openr2_chan_t *r2chan)
@@ -662,14 +641,13 @@ static void ftdm_r2_on_chan_log(openr2_chan_t *r2chan, const char *file, const c
 	openr2_log_level_t level, const char *fmt, va_list ap)
 {
 	ftdm_channel_t *ftdmchan = openr2_chan_get_client_data(r2chan);
-#define CHAN_TAG "Chan "
-	char logmsg[512];
-	char completemsg[sizeof(logmsg) + sizeof(CHAN_TAG) - 1];
+	char logmsg[1024];
+	char completemsg[sizeof(logmsg)];
 	vsnprintf(logmsg, sizeof(logmsg), fmt, ap);
-	snprintf(completemsg, sizeof(completemsg), CHAN_TAG "%d:%d [%s] %s", 
-			ftdmchan->span_id, ftdmchan->chan_id, ftdm_channel_state2str(ftdmchan->state), logmsg);
+	snprintf(completemsg, sizeof(completemsg), "[s%dc%d] [%d:%d] [%s] %s", 
+			ftdmchan->span_id, ftdmchan->chan_id, ftdmchan->physical_span_id, ftdmchan->physical_chan_id,
+			ftdm_channel_state2str(ftdmchan->state), logmsg);
 	ftdm_r2_write_log(level, file, function, line, completemsg);
-#undef CHAN_TAG
 }
 
 static int ftdm_r2_on_dnis_digit_received(openr2_chan_t *r2chan, char digit)
@@ -808,7 +786,7 @@ static int ftdm_r2_io_wait(openr2_chan_t *r2chan, int *flags, int block)
 	int32_t timeout;
 	ftdm_wait_flag_t ftdmflags = 0;
 
-	ftdm_channel_t *ftdm_chan = openr2_chan_get_fd(r2chan);
+	ftdm_channel_t *fchan = openr2_chan_get_fd(r2chan);
 	timeout = block ? -1 : 0;
 
 	if (*flags & OR2_IO_READ) {
@@ -821,9 +799,10 @@ static int ftdm_r2_io_wait(openr2_chan_t *r2chan, int *flags, int block)
 		ftdmflags |= FTDM_EVENTS;
 	}
 	
-	status = ftdm_channel_wait(ftdm_chan, &ftdmflags, timeout);
+	status = ftdm_channel_wait(fchan, &ftdmflags, timeout);
 
 	if (FTDM_SUCCESS != status && FTDM_TIMEOUT != status) {
+		ftdm_log_chan_msg(fchan, FTDM_LOG_ERROR, "Failed to wait for events on channel\n");
 		return -1;
 	}
 
@@ -867,9 +846,36 @@ static int ftdm_r2_io_setup(openr2_chan_t *r2chan)
 
 static int ftdm_r2_io_get_oob_event(openr2_chan_t *r2chan, openr2_oob_event_t *event)
 {
-	*event = 0;
-	ftdm_log(FTDM_LOG_ERROR, "I should not be called (I/O get oob event)!!\n");
-	return 0;
+    ftdm_status_t status;
+    ftdm_event_t *fevent = NULL;
+    ftdm_channel_t *ftdmchan = openr2_chan_get_fd(r2chan);
+
+    *event = OR2_OOB_EVENT_NONE;
+    status = ftdm_channel_read_event(ftdmchan, &fevent);
+    if (status != FTDM_SUCCESS) {
+		ftdm_log_chan_msg(ftdmchan, FTDM_LOG_ERROR, "failed to retrieve freetdm event!\n");
+        return -1;
+    }
+	if (fevent->e_type != FTDM_EVENT_OOB)
+		return 0;
+	switch (fevent->enum_id) {
+		case FTDM_OOB_CAS_BITS_CHANGE:
+			{
+				*event = OR2_OOB_EVENT_CAS_CHANGE;
+			}
+			break;
+		case FTDM_OOB_ALARM_TRAP:
+			{
+				*event = OR2_OOB_EVENT_ALARM_ON;
+			}
+			break;
+		case FTDM_OOB_ALARM_CLEAR:
+			{
+				*event = OR2_OOB_EVENT_ALARM_OFF;
+			}
+			break;
+	}
+    return 0;
 }
 
 static openr2_io_interface_t ftdm_r2_io_iface = {
@@ -885,27 +891,147 @@ static openr2_io_interface_t ftdm_r2_io_iface = {
 	/* .get_oob_event */ ftdm_r2_io_get_oob_event /* never called */
 };
 
-static FIO_SIG_CONFIGURE_FUNCTION(ftdm_r2_configure_span)
-	//ftdm_status_t (ftdm_span_t *span, fio_signal_cb_t sig_cb, va_list ap)
+/* resolve a loglevel string, such as "debug,notice,warning",  to an openr2 log level integer */
+static openr2_log_level_t ftdm_r2_loglevel_from_string(const char *level)
+{
+	openr2_log_level_t tmplevel;
+	openr2_log_level_t newlevel = 0;
+	char *clevel = NULL;
+	char *logval = NULL;
+
+	logval = ftdm_malloc(strlen(level)+1); /* alloca man page scared me, so better to use good ol' malloc  */
+	if (!logval) {
+		ftdm_log(FTDM_LOG_WARNING, "Ignoring R2 logging parameter: '%s', failed to alloc memory\n", level);
+		return newlevel;
+	}
+	strcpy(logval, level);
+	while (logval) {
+		clevel = strsep(&logval, ",");
+		if (-1 == (tmplevel = openr2_log_get_level(clevel))) {
+			ftdm_log(FTDM_LOG_WARNING, "Ignoring invalid R2 logging level: '%s'\n", clevel);
+			continue;
+		}
+		newlevel |= tmplevel;
+	}
+	ftdm_safe_free(logval);
+	return newlevel;
+}
+
+static ftdm_state_map_t r2_state_map = {
+	{
+		{
+			ZSD_INBOUND,
+			ZSM_UNACCEPTABLE,
+			{FTDM_CHANNEL_STATE_DOWN, FTDM_END},
+			{FTDM_CHANNEL_STATE_COLLECT, FTDM_END}
+		},
+		{
+			ZSD_INBOUND,
+			ZSM_UNACCEPTABLE,
+			{FTDM_CHANNEL_STATE_COLLECT, FTDM_END},
+			{FTDM_CHANNEL_STATE_RING, FTDM_CHANNEL_STATE_TERMINATING, FTDM_END}
+		},
+		{
+			ZSD_INBOUND,
+			ZSM_UNACCEPTABLE,
+			{FTDM_CHANNEL_STATE_RING, FTDM_END},
+			{FTDM_CHANNEL_STATE_HANGUP, FTDM_CHANNEL_STATE_TERMINATING, FTDM_CHANNEL_STATE_PROGRESS, FTDM_CHANNEL_STATE_PROGRESS_MEDIA, FTDM_CHANNEL_STATE_UP, FTDM_END}
+		},
+		{
+			ZSD_INBOUND,
+			ZSM_UNACCEPTABLE,
+			{FTDM_CHANNEL_STATE_HANGUP, FTDM_END},
+			{FTDM_CHANNEL_STATE_DOWN, FTDM_END},
+		},
+		{
+			ZSD_INBOUND,
+			ZSM_UNACCEPTABLE,
+			{FTDM_CHANNEL_STATE_TERMINATING, FTDM_END},
+			{FTDM_CHANNEL_STATE_HANGUP, FTDM_END},
+		},
+		{
+			ZSD_INBOUND,
+			ZSM_UNACCEPTABLE,
+			{FTDM_CHANNEL_STATE_PROGRESS, FTDM_END},
+			{FTDM_CHANNEL_STATE_HANGUP, FTDM_CHANNEL_STATE_TERMINATING, FTDM_CHANNEL_STATE_PROGRESS_MEDIA, FTDM_CHANNEL_STATE_UP, FTDM_END},
+		},
+		{
+			ZSD_INBOUND,
+			ZSM_UNACCEPTABLE,
+			{FTDM_CHANNEL_STATE_PROGRESS_MEDIA, FTDM_END},
+			{FTDM_CHANNEL_STATE_HANGUP, FTDM_CHANNEL_STATE_TERMINATING, FTDM_CHANNEL_STATE_UP, FTDM_END},
+		},
+		{
+			ZSD_INBOUND,
+			ZSM_UNACCEPTABLE,
+			{FTDM_CHANNEL_STATE_UP, FTDM_END},
+			{FTDM_CHANNEL_STATE_HANGUP, FTDM_CHANNEL_STATE_TERMINATING, FTDM_END},
+		},
+		
+		/* Outbound states */
+		
+		{
+			ZSD_OUTBOUND,
+			ZSM_UNACCEPTABLE,
+			{FTDM_CHANNEL_STATE_DOWN, FTDM_END},
+			{FTDM_CHANNEL_STATE_DIALING, FTDM_END}
+		},
+
+		{
+			ZSD_OUTBOUND,
+			ZSM_UNACCEPTABLE,
+			{FTDM_CHANNEL_STATE_DIALING, FTDM_END},
+			{FTDM_CHANNEL_STATE_HANGUP, FTDM_CHANNEL_STATE_TERMINATING, FTDM_CHANNEL_STATE_PROGRESS_MEDIA, FTDM_END}
+		},
+
+		{
+			ZSD_OUTBOUND,
+			ZSM_UNACCEPTABLE,
+			{FTDM_CHANNEL_STATE_HANGUP, FTDM_END},
+			{FTDM_CHANNEL_STATE_DOWN, FTDM_END}
+		},
+
+		{
+			ZSD_OUTBOUND,
+			ZSM_UNACCEPTABLE,
+			{FTDM_CHANNEL_STATE_TERMINATING, FTDM_END},
+			{FTDM_CHANNEL_STATE_HANGUP, FTDM_END}
+		},
+
+		{
+			ZSD_OUTBOUND,
+			ZSM_UNACCEPTABLE,
+			{FTDM_CHANNEL_STATE_PROGRESS_MEDIA, FTDM_END},
+			{FTDM_CHANNEL_STATE_HANGUP, FTDM_CHANNEL_STATE_TERMINATING, FTDM_CHANNEL_STATE_UP, FTDM_END}
+		},
+
+		{
+			ZSD_OUTBOUND,
+			ZSM_UNACCEPTABLE,
+			{FTDM_CHANNEL_STATE_UP, FTDM_END},
+			{FTDM_CHANNEL_STATE_HANGUP, FTDM_CHANNEL_STATE_TERMINATING, FTDM_END}
+		},
+	}
+};
+
+static FIO_CONFIGURE_SPAN_SIGNALING_FUNCTION(ftdm_r2_configure_span_signaling)
 {
-	int i = 0;
+	unsigned int i = 0;
 	int conf_failure = 0;
-	char *var = NULL;
-	char *val = NULL;
+	const char *var = NULL, *val = NULL;
+	const char *log_level = "notice,warning,error"; /* default loglevel, if none is read from conf */
 	ftdm_r2_data_t *r2data = NULL;
 	ftdm_r2_span_pvt_t *spanpvt = NULL;
 	ftdm_r2_call_t *r2call = NULL;
 	openr2_chan_t *r2chan = NULL;
-	openr2_log_level_t tmplevel;
-	char *clevel = NULL;
-	char *logval = NULL;
+	unsigned paramindex = 0;
 
 	ft_r2_conf_t r2conf = 
 	{
 		/* .variant */ OR2_VAR_ITU,
 		/* .category */ OR2_CALLING_PARTY_CATEGORY_NATIONAL_SUBSCRIBER,
 		/* .loglevel */ OR2_LOG_ERROR | OR2_LOG_WARNING,
-		/* .logdir */ NULL,
+		/* .logdir */ (char *)"/usr/local/freeswitch/log/", /* FIXME: get PREFIX variable */
 		/* .advanced_protocol_file */ NULL,
 		/* .max_ani */ 10,
 		/* .max_dnis */ 4,
@@ -916,7 +1042,7 @@ static FIO_SIG_CONFIGURE_FUNCTION(ftdm_r2_configure_span)
 		/* .get_ani_first */ -1,
 		/* .call_files */ 0,
 		/* .mf_files */ 0,
-		/* .double_answer */ 0,
+		/* .double_answer */ -1,
 		/* .charge_calls */ -1,
 		/* .forced_release */ -1,
 		/* .allow_collect_calls */ -1
@@ -929,10 +1055,12 @@ static FIO_SIG_CONFIGURE_FUNCTION(ftdm_r2_configure_span)
 		return FTDM_FAIL;
 	}
 
-	while ((var = va_arg(ap, char *))) {
+	for (; ftdm_parameters[paramindex].var; paramindex++) {
+		var = ftdm_parameters[paramindex].var;
+		val = ftdm_parameters[paramindex].val;
 		ftdm_log(FTDM_LOG_DEBUG, "Reading R2 parameter %s for span %d\n", var, span->span_id);
 		if (!strcasecmp(var, "variant")) {
-			if (!(val = va_arg(ap, char *))) {
+			if (!val) {
 				break;
 			}
 			if (ftdm_strlen_zero_buf(val)) {
@@ -947,7 +1075,7 @@ static FIO_SIG_CONFIGURE_FUNCTION(ftdm_r2_configure_span)
 			}
 			ftdm_log(FTDM_LOG_DEBUG, "Configuring R2 span %d for variant %s\n", span->span_id, val);
 		} else if (!strcasecmp(var, "category")) {
-			if (!(val = va_arg(ap, char *))) {
+			if (!val) {
 				break;
 			}
 			if (ftdm_strlen_zero_buf(val)) {
@@ -962,87 +1090,72 @@ static FIO_SIG_CONFIGURE_FUNCTION(ftdm_r2_configure_span)
 			}
 			ftdm_log(FTDM_LOG_DEBUG, "Configuring R2 span %d with default category %s\n", span->span_id, val);
 		} else if (!strcasecmp(var, "logdir")) {
-			if (!(val = va_arg(ap, char *))) {
+			if (!val) {
 				break;
 			}
 			if (ftdm_strlen_zero_buf(val)) {
 				ftdm_log(FTDM_LOG_NOTICE, "Ignoring empty R2 logdir parameter\n");
 				continue;
 			}
-			r2conf.logdir = val;
+			r2conf.logdir = (char *)val;
 			ftdm_log(FTDM_LOG_DEBUG, "Configuring R2 span %d with logdir %s\n", span->span_id, val);
 		} else if (!strcasecmp(var, "logging")) {
-			if (!(val = va_arg(ap, char *))) {
+			if (!val) {
 				break;
 			}
 			if (ftdm_strlen_zero_buf(val)) {
 				ftdm_log(FTDM_LOG_NOTICE, "Ignoring empty R2 logging parameter\n");
 				continue;
 			}
-			logval = ftdm_malloc(strlen(val)+1); /* alloca man page scared me, so better to use good ol' malloc  */
-			if (!logval) {
-				ftdm_log(FTDM_LOG_WARNING, "Ignoring R2 logging parameter: '%s', failed to alloc memory\n", val);
-				continue;
-			}
-			strcpy(logval, val);
-			while (logval) {
-				clevel = strsep(&logval, ",");
-				if (-1 == (tmplevel = openr2_log_get_level(clevel))) {
-					ftdm_log(FTDM_LOG_WARNING, "Ignoring invalid R2 logging level: '%s'\n", clevel);
-					continue;
-				}
-				r2conf.loglevel |= tmplevel;
-				ftdm_log(FTDM_LOG_DEBUG, "Configuring R2 span %d with loglevel %s\n", span->span_id, clevel);
-			}
-			ftdm_safe_free(logval);
+			log_level = val;
 		} else if (!strcasecmp(var, "advanced_protocol_file")) {
-			if (!(val = va_arg(ap, char *))) {
+			if (!val) {
 				break;
 			}
 			if (ftdm_strlen_zero_buf(val)) {
 				ftdm_log(FTDM_LOG_NOTICE, "Ignoring empty R2 advanced_protocol_file parameter\n");
 				continue;
 			}
-			r2conf.advanced_protocol_file = val;
+			r2conf.advanced_protocol_file = (char *)val;
 			ftdm_log(FTDM_LOG_DEBUG, "Configuring R2 span %d with advanced protocol file %s\n", span->span_id, val);
 		} else if (!strcasecmp(var, "allow_collect_calls")) {
-			r2conf.allow_collect_calls = va_arg(ap, int);
+			r2conf.allow_collect_calls = ftdm_true(val);
 			ftdm_log(FTDM_LOG_DEBUG, "Configuring R2 span %d with allow collect calls max ani = %d\n", span->span_id, r2conf.allow_collect_calls);
 		} else if (!strcasecmp(var, "double_answer")) {
-			r2conf.double_answer = va_arg(ap, int);
+			r2conf.double_answer = ftdm_true(val);
 			ftdm_log(FTDM_LOG_DEBUG, "Configuring R2 span %d with double answer = %d\n", span->span_id, r2conf.double_answer);
 		} else if (!strcasecmp(var, "immediate_accept")) {
-			r2conf.immediate_accept = va_arg(ap, int);
+			r2conf.immediate_accept = ftdm_true(val);
 			ftdm_log(FTDM_LOG_DEBUG, "Configuring R2 span %d with immediate accept = %d\n", span->span_id, r2conf.immediate_accept);
 		} else if (!strcasecmp(var, "skip_category")) {
-			r2conf.skip_category = va_arg(ap, int);
+			r2conf.skip_category = ftdm_true(val);
 			ftdm_log(FTDM_LOG_DEBUG, "Configuring R2 span %d with skip category = %d\n", span->span_id, r2conf.skip_category);
 		} else if (!strcasecmp(var, "forced_release")) {
-			r2conf.forced_release = va_arg(ap, int);
+			r2conf.forced_release = ftdm_true(val);
 			ftdm_log(FTDM_LOG_DEBUG, "Configuring R2 span %d with forced release = %d\n", span->span_id, r2conf.forced_release);
 		} else if (!strcasecmp(var, "charge_calls")) {
-			r2conf.charge_calls = va_arg(ap, int);
+			r2conf.charge_calls = ftdm_true(val);
 			ftdm_log(FTDM_LOG_DEBUG, "Configuring R2 span %d with charge calls = %d\n", span->span_id, r2conf.charge_calls);
 		} else if (!strcasecmp(var, "get_ani_first")) {
-			r2conf.get_ani_first = va_arg(ap, int);
+			r2conf.get_ani_first = ftdm_true(val);
 			ftdm_log(FTDM_LOG_DEBUG, "Configuring R2 span %d with get ani first = %d\n", span->span_id, r2conf.get_ani_first);
 		} else if (!strcasecmp(var, "call_files")) {
-			r2conf.call_files = va_arg(ap, int);
+			r2conf.call_files = ftdm_true(val);
 			ftdm_log(FTDM_LOG_DEBUG, "Configuring R2 span %d with call files = %d\n", span->span_id, r2conf.call_files);
 		} else if (!strcasecmp(var, "mf_files")) {
-			r2conf.mf_files = va_arg(ap, int);
+			r2conf.mf_files = ftdm_true(val);
 			ftdm_log(FTDM_LOG_DEBUG, "Configuring R2 span %d with mf files = %d\n", span->span_id, r2conf.mf_files);
 		} else if (!strcasecmp(var, "mfback_timeout")) {
-			r2conf.mfback_timeout = va_arg(ap, int);
+			r2conf.mfback_timeout = atoi(val);
 			ftdm_log(FTDM_LOG_DEBUG, "Configuring R2 span %d with MF backward timeout = %dms\n", span->span_id, r2conf.mfback_timeout);
 		} else if (!strcasecmp(var, "metering_pulse_timeout")) {
-			r2conf.metering_pulse_timeout = va_arg(ap, int);
+			r2conf.metering_pulse_timeout = atoi(val);
 			ftdm_log(FTDM_LOG_DEBUG, "Configuring R2 span %d with metering pulse timeout = %dms\n", span->span_id, r2conf.metering_pulse_timeout);
 		} else if (!strcasecmp(var, "max_ani")) {
-			r2conf.max_ani = va_arg(ap, int);
+			r2conf.max_ani = atoi(val);
 			ftdm_log(FTDM_LOG_DEBUG, "Configuring R2 span %d with max ani = %d\n", span->span_id, r2conf.max_ani);
 		} else if (!strcasecmp(var, "max_dnis")) {
-			r2conf.max_dnis = va_arg(ap, int);
+			r2conf.max_dnis = atoi(val);
 			ftdm_log(FTDM_LOG_DEBUG, "Configuring R2 span %d with max dnis = %d\n", span->span_id, r2conf.max_dnis);
 		} else {
 			snprintf(span->last_error, sizeof(span->last_error), "Unknown R2 parameter [%s]", var);
@@ -1055,6 +1168,10 @@ static FIO_SIG_CONFIGURE_FUNCTION(ftdm_r2_configure_span)
 		return FTDM_FAIL;
 	}
 
+	/* set span log level */
+	r2conf.loglevel = ftdm_r2_loglevel_from_string(log_level);
+	ftdm_log(FTDM_LOG_DEBUG, "Configuring R2 span %d with loglevel %s\n", span->span_id, log_level);
+
 	r2data = ftdm_malloc(sizeof(*r2data));
 	if (!r2data) {
 		snprintf(span->last_error, sizeof(span->last_error), "Failed to allocate R2 data.");
@@ -1106,11 +1223,6 @@ static FIO_SIG_CONFIGURE_FUNCTION(ftdm_r2_configure_span)
 		openr2_chan_set_log_level(r2chan, r2conf.loglevel);
 		if (r2conf.call_files) {
 			openr2_chan_enable_call_files(r2chan);
-#if 0
-			if (r2conf.mf_files) {
-				openr2_chan_enable_mf_files(r2chan);
-			}
-#endif
 		}
 
 		r2call = ftdm_malloc(sizeof(*r2call));
@@ -1137,13 +1249,15 @@ static FIO_SIG_CONFIGURE_FUNCTION(ftdm_r2_configure_span)
 
 	span->start = ftdm_r2_start;
 	span->stop = ftdm_r2_stop;
-	span->sig_read = ftdm_r2_sig_read;
+	span->sig_read = NULL;
 
 	span->signal_cb = sig_cb;
 	span->signal_type = FTDM_SIGTYPE_R2;
 	span->signal_data = r2data;
 	span->outgoing_call = r2_outgoing_call;
 
+	span->state_map = &r2_state_map;
+
 	/* use signals queue */
 	ftdm_set_flag(span, FTDM_SPAN_USE_SIGNALS_QUEUE);
 
@@ -1177,25 +1291,27 @@ static int ftdm_r2_state_advance(ftdm_channel_t *ftdmchan)
 
 	ret = 0;
 
-	if (R2CALL(ftdmchan)->state_ack_pending) {
-		ftdm_clear_flag(ftdmchan, FTDM_CHANNEL_STATE_CHANGE);
-		ftdm_channel_complete_state(ftdmchan);
-		R2CALL(ftdmchan)->state_ack_pending = 0;
-	}
-
-	if (ftdm_test_flag(ftdmchan, FTDM_CHANNEL_STATE_CHANGE) && (R2CALL(ftdmchan)->chanstate != ftdmchan->state)) {
+	/* because we do not always acknowledge the state change (clearing the FTDM_CHANNEL_STATE_CHANGE flag) due to the accept
+	 * procedure described below, we need the chanstate member to NOT process some states twice, so is valid entering this 
+	 * function with the FTDM_CHANNEL_STATE_CHANGE flag set but with a state that was already processed and is just waiting
+	 * to complete (the processing is media-bound)
+	 * */
+	if (ftdm_test_flag(ftdmchan, FTDM_CHANNEL_STATE_CHANGE) 
+			&& (R2CALL(ftdmchan)->chanstate != ftdmchan->state)) {
 
 		ftdm_log_chan(ftdmchan, FTDM_LOG_DEBUG, "Executing state handler for %s\n", ftdm_channel_state2str(ftdmchan->state));
 		R2CALL(ftdmchan)->chanstate = ftdmchan->state;
 
-		if (!ftdm_test_flag(ftdmchan, FTDM_CHANNEL_OUTBOUND) && !R2CALL(ftdmchan)->accepted &&
-				(ftdmchan->state == FTDM_CHANNEL_STATE_PROGRESS ||
-				 ftdmchan->state == FTDM_CHANNEL_STATE_PROGRESS_MEDIA ||
-				 ftdmchan->state == FTDM_CHANNEL_STATE_UP) ) {
-			/* if an accept ack will be required we should not acknowledge the state change just yet, 
-			   it will be done below after processing the MF signals, otherwise we have a race condition between freetdm calling
-			   openr2_chan_answer_call and openr2 accepting the call first, if freetdm calls openr2_chan_answer_call before the accept cycle
-			   completes, openr2 will fail to answer the call */
+		if (IS_ACCEPTING_PENDING(ftdmchan)) {
+			/* 
+			   Moving to PROGRESS, PROGRESS_MEDIA or UP means that we must accept the call first, and accepting
+			   the call in R2 means sending a tone, then waiting for the acknowledge from the other end,
+			   since all of that requires sending and detecting tones, it takes a few milliseconds (I'd say around 100)
+			   which means during that time the user should not try to perform any operations like answer, hangup or anything
+			   else, therefore we DO NOT clear the FTDM_CHANNEL_STATE_CHANGE flag here, we rely on ftdm_io.c to block
+			   the user thread until we're done with the accept (see on_call_accepted callback) and then we clear the state change flag,
+			   otherwise we have a race condition between freetdm calling openr2_chan_answer_call and openr2 accepting the call first, 
+			   if freetdm calls openr2_chan_answer_call before the accept cycle completes, openr2 will fail to answer the call */
 			ftdm_log_chan(ftdmchan, FTDM_LOG_DEBUG, "State ack for state %s will have to wait a bit\n", ftdm_channel_state2str(ftdmchan->state));
 		} else if (ftdmchan->state != FTDM_CHANNEL_STATE_DOWN){
 			ftdm_clear_flag(ftdmchan, FTDM_CHANNEL_STATE_CHANGE);
@@ -1211,6 +1327,7 @@ static int ftdm_r2_state_advance(ftdm_channel_t *ftdmchan)
 					ftdm_channel_command(ftdmchan, FTDM_COMMAND_GET_INTERVAL, &interval);
 					ftdm_assert(interval != 0, "Invalid interval!");
 					ftdm_log_chan(ftdmchan, FTDM_LOG_DEBUG, "Starting processing of incoming call with interval %d\n", interval);
+					openr2_chan_enable_read(r2chan);
 				}
 				break;
 
@@ -1222,6 +1339,7 @@ static int ftdm_r2_state_advance(ftdm_channel_t *ftdmchan)
 					ftdm_assert(interval != 0, "Invalid interval!");
 					ftdm_log_chan(ftdmchan, 
 						FTDM_LOG_DEBUG, "Starting processing of outgoing call in channel with interval %d\n", interval);
+					openr2_chan_enable_read(r2chan);
 				}
 				break;
 
@@ -1237,7 +1355,7 @@ static int ftdm_r2_state_advance(ftdm_channel_t *ftdmchan)
 					ftdm_set_state(ftdmchan, FTDM_CHANNEL_STATE_CANCEL);
 					break; 
 				}
-				R2CALL(ftdmchan)->ftdm_started = 1; 
+				R2CALL(ftdmchan)->ftdm_call_started = 1; 
 
 				break;
 
@@ -1252,10 +1370,11 @@ static int 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;
-						if (ftdm_span_send_signal(ftdmchan->span, &sigev) != FTDM_SUCCESS) {
-							ftdm_set_state(ftdmchan, FTDM_CHANNEL_STATE_HANGUP);
-						}
+						ftdm_span_send_signal(ftdmchan->span, &sigev);
 					}
 				}
 				break;
@@ -1276,25 +1395,40 @@ static int ftdm_r2_state_advance(ftdm_channel_t *ftdmchan)
 					} else {
 						ftdm_log_chan_msg(ftdmchan, FTDM_LOG_DEBUG, "Notifying of call answered\n");
 						sigev.event_id = FTDM_SIGEVENT_UP;
-						if (ftdm_span_send_signal(ftdmchan->span, &sigev) != FTDM_SUCCESS) {
-							ftdm_set_state(ftdmchan, FTDM_CHANNEL_STATE_HANGUP);
-						}
+						ftdm_span_send_signal(ftdmchan->span, &sigev);
 					}
 				}
 				break;
 
 				/* just got hangup */
-			case FTDM_CHANNEL_STATE_HANGUP: 
+			case FTDM_CHANNEL_STATE_HANGUP:
 				{
-					openr2_call_disconnect_cause_t disconnect_cause = ftdm_r2_ftdm_cause_to_openr2_cause(ftdmchan);
-					ftdm_log_chan(ftdmchan, FTDM_LOG_DEBUG, "Clearing call, cause = %s\n", openr2_proto_get_disconnect_string(disconnect_cause));
-					openr2_chan_enable_read(r2chan);
 					if (!R2CALL(ftdmchan)->disconnect_rcvd) {
+						openr2_call_disconnect_cause_t disconnect_cause = ftdm_r2_ftdm_cause_to_openr2_cause(ftdmchan);
+						ftdm_log_chan(ftdmchan, FTDM_LOG_DEBUG, "Clearing call, cause = %s\n", openr2_proto_get_disconnect_string(disconnect_cause));
 						/* this will disconnect the call, but need to wait for the call end before moving to DOWN */
 						openr2_chan_disconnect_call(r2chan, disconnect_cause);
-					} else {
+					} else if (!R2CALL(ftdmchan)->protocol_error) {
 						/* just ack the hangup, on_call_end will be called by openr2 right after */
-						openr2_chan_disconnect_call(r2chan, disconnect_cause);
+						openr2_chan_disconnect_call(r2chan, OR2_CAUSE_NORMAL_CLEARING);
+					} else {
+						ftdm_log_chan_msg(ftdmchan, FTDM_LOG_ERROR, "Clearing call due to protocol error\n");
+						ftdm_set_state(ftdmchan, FTDM_CHANNEL_STATE_DOWN);
+					}
+				}
+				break;
+
+			case FTDM_CHANNEL_STATE_TERMINATING:
+				{
+					/* if the call has not been started yet we must go to HANGUP right here */ 
+					if (!R2CALL(ftdmchan)->ftdm_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);
+						ftdm_log_chan(ftdmchan, FTDM_LOG_DEBUG, "Clearing call, cause = %s\n", openr2_proto_get_disconnect_string(disconnect_cause));
+						/* notify the user of the call terminating and we wait for the user to move us to hangup */
+						sigev.event_id = FTDM_SIGEVENT_STOP;
+						ftdm_span_send_signal(ftdmchan->span, &sigev);
 					}
 				}
 				break;
@@ -1303,7 +1437,6 @@ static int ftdm_r2_state_advance(ftdm_channel_t *ftdmchan)
 			case FTDM_CHANNEL_STATE_CANCEL:
 				{
 					ftdm_log_chan_msg(ftdmchan, FTDM_LOG_DEBUG, "Unable to receive call\n");
-					openr2_chan_enable_read(r2chan);
 					openr2_chan_disconnect_call(r2chan, OR2_CAUSE_OUT_OF_ORDER);
 				}
 				break;
@@ -1315,6 +1448,7 @@ static int ftdm_r2_state_advance(ftdm_channel_t *ftdmchan)
 					if (R2CALL(ftdmchan)->txdrops) {
 						ftdm_log_chan(ftdmchan, FTDM_LOG_WARNING, "dropped %d tx packets\n", R2CALL(ftdmchan)->txdrops);
 					}
+					openr2_chan_disable_read(r2chan);
 					ret = 1;
 				}
 				break;
@@ -1337,19 +1471,34 @@ static int ftdm_r2_state_advance(ftdm_channel_t *ftdmchan)
 	return ret;
 }
 
+/* the channel must be locked when calling this function */
+static void ftdm_r2_state_advance_all(ftdm_channel_t *ftdmchan)
+{
+	/* because we do not always acknowledge the state change (clearing the FTDM_CHANNEL_STATE_CHANGE flag) due to the accept
+	 * procedure described below, we need the chanstate member to NOT process some states twice, so is valid entering this 
+	 * function with the FTDM_CHANNEL_STATE_CHANGE flag set but with a state that was already processed and is just waiting
+	 * to complete (the processing is media-bound)
+	 * */
+	while (ftdm_test_flag(ftdmchan, FTDM_CHANNEL_STATE_CHANGE)
+		&& (R2CALL(ftdmchan)->chanstate != ftdmchan->state)) {
+		ftdm_r2_state_advance(ftdmchan);
+	}
+}
+
 static void *ftdm_r2_run(ftdm_thread_t *me, void *obj)
 {
 	openr2_chan_t *r2chan;
-	ftdm_r2_call_t *r2call = NULL;
 	ftdm_channel_t *ftdmchan = NULL;
 	ftdm_status_t status;
 	ftdm_span_t *span = (ftdm_span_t *) obj;
 	ftdm_r2_data_t *r2data = span->signal_data;
 	int waitms = 20;
-	int i, res;
-	int ms;
+	unsigned int i;
+	int res, ms;
+	int index = 0;
 	struct timeval start, end;
-    short *poll_events = ftdm_malloc(sizeof(short)*span->chan_count);
+	ftdm_iterator_t *chaniter = NULL;
+	short *poll_events = ftdm_malloc(sizeof(short) * span->chan_count);
 
 #ifdef __linux__
 	r2data->monitor_thread_id = syscall(SYS_gettid);	
@@ -1361,29 +1510,43 @@ static void *ftdm_r2_run(ftdm_thread_t *me, void *obj)
 		r2chan = R2CALL(span->channels[i])->r2chan;
 		openr2_chan_set_idle(r2chan);
 		openr2_chan_process_cas_signaling(r2chan);
+
+		ftdmchan = openr2_chan_get_client_data(r2chan);
+		//ftdm_channel_set_feature(ftdmchan, FTDM_CHANNEL_FEATURE_IO_STATS);
 	}
 
 	memset(&start, 0, sizeof(start));
 	memset(&end, 0, sizeof(end));
+	chaniter = ftdm_span_get_chan_iterator(span, NULL);
 	while (ftdm_running() && ftdm_test_flag(r2data, FTDM_R2_RUNNING)) {
-		r2data->loops++;
 		res = gettimeofday(&end, NULL);
 		if (start.tv_sec) {
 			ms = ((end.tv_sec - start.tv_sec) * 1000) 
 			    + ((( 1000000 + end.tv_usec - start.tv_usec) / 1000) - 1000);
+			if (ms < 0) {
+				ms = 0;
+			}
 			if (ms > r2data->jobmax) {
 				r2data->jobmax = ms;
 			}
+			index = (ms / 10);
+			index = (index > 10) ? 10 : index;
+			r2data->loops[index]++;
+			r2data->total_loops++;
 		}
 
 #ifndef WIN32
 		 /* figure out what event to poll each channel for. POLLPRI when the channel is down,
 		  * POLLPRI|POLLIN|POLLOUT otherwise */
 		memset(poll_events, 0, sizeof(short)*span->chan_count);
-		for (i = 0; i < span->chan_count; i++) {
-			r2chan = R2CALL(span->channels[(i+1)])->r2chan;
-			ftdmchan = openr2_chan_get_client_data(r2chan);
-			poll_events[i] = ftdmchan->state == FTDM_CHANNEL_STATE_DOWN ? POLLPRI : (POLLPRI | POLLIN | POLLOUT);
+		chaniter = ftdm_span_get_chan_iterator(span, chaniter);
+		for (i = 0; chaniter; chaniter = ftdm_iterator_next(chaniter), i++) {
+			ftdmchan = ftdm_iterator_current(chaniter);
+			r2chan = R2CALL(ftdmchan)->r2chan;
+			poll_events[i] = POLLPRI;
+			if (openr2_chan_get_read_enabled(r2chan)) {
+				poll_events[i] |= POLLIN;
+			}
 		}
 
 		status = ftdm_span_poll_event(span, waitms, poll_events);
@@ -1401,70 +1564,37 @@ static void *ftdm_r2_run(ftdm_thread_t *me, void *obj)
 			continue;
 		}
 
-		 if (FTDM_SUCCESS == status) {
-			ftdm_event_t *event;
-			while (ftdm_span_next_event(span, &event) == FTDM_SUCCESS) {
-				if (event->enum_id == FTDM_OOB_CAS_BITS_CHANGE) {
-					r2call = R2CALL(event->channel);
-					r2chan = r2call->r2chan;
-
-					ftdm_log(FTDM_LOG_DEBUG, "Handling CAS on channel %d.\n", openr2_chan_get_number(r2chan));
-					// we only expect CAS and other OOB events on this thread/loop, once a call is started
-					// the MF events (in-band signaling) are handled in the call thread
-					openr2_chan_process_cas_signaling(r2chan);
-				} else {
-					ftdm_log(FTDM_LOG_DEBUG, "Ignoring event %d on channel %d.\n", event->enum_id, openr2_chan_get_number(r2chan));
-					// XXX TODO: handle alarms here XXX
-				}
-			}
+		/* this main loop takes care of MF and CAS signaling during call setup and tear down
+		 * for every single channel in the span, do not perform blocking operations here! */
+		chaniter = ftdm_span_get_chan_iterator(span, chaniter);
+		for ( ; chaniter; chaniter = ftdm_iterator_next(chaniter)) {
+			ftdmchan = ftdm_iterator_current(chaniter);
 
-			/* XXX
-			* when ftdm_span_poll_event() returns FTDM_SUCCESS, means there are events pending on the span.
-			* is it possible to know on which channels those events are pending, without traversing the span?
-			* XXX */
-			for (i = 1; i <= span->chan_count; i++) {
-				r2chan = R2CALL(span->channels[i])->r2chan;
-				ftdmchan = openr2_chan_get_client_data(r2chan);
-				r2call = R2CALL(ftdmchan);
-
-				ftdm_mutex_lock(ftdmchan->mutex);
-				ftdm_set_flag(r2call, FTDM_R2_PROCESSING);
-
-				if (ftdm_r2_state_advance(ftdmchan)) {
-					ftdm_clear_flag(r2call, FTDM_R2_PROCESSING);
-					ftdm_mutex_unlock(ftdmchan->mutex);
-					continue;
-				}
+			ftdm_mutex_lock(ftdmchan->mutex);
 
-				/* handle timeout events first if any */
-				openr2_chan_run_schedule(r2chan);
+			ftdm_r2_state_advance_all(ftdmchan);
 
-				/* process mf tones, if any */
-				if (openr2_chan_get_read_enabled(r2chan)) {
-					openr2_chan_process_mf_signaling(r2chan);
-				}
+			r2chan = R2CALL(ftdmchan)->r2chan;
+			openr2_chan_process_signaling(r2chan);
 
-				if (ftdm_r2_state_advance(ftdmchan)) {
-					ftdm_clear_flag(r2call, FTDM_R2_PROCESSING);
-					ftdm_mutex_unlock(ftdmchan->mutex);
-					continue;
-				}
+			ftdm_r2_state_advance_all(ftdmchan);
 
-				ftdm_clear_flag(r2call, FTDM_R2_PROCESSING);
-				ftdm_mutex_unlock(ftdmchan->mutex);
-			}
-		} else if (status != FTDM_TIMEOUT) {
-			ftdm_log(FTDM_LOG_ERROR, "ftdm_span_poll_event returned %d.\n", status);
+			ftdm_mutex_unlock(ftdmchan->mutex);
 		}
+		/* deliver the actual events to the user now without any channel locking */
 		ftdm_span_trigger_signals(span);
-		ftdm_sleep(20);
 	}
-
-	for (i = 1; i <= span->chan_count; i++) {
-		r2chan = R2CALL(span->channels[i])->r2chan;
+	
+	chaniter = ftdm_span_get_chan_iterator(span, chaniter);
+	for ( ; chaniter; chaniter = ftdm_iterator_next(chaniter)) {
+		ftdmchan = ftdm_iterator_current(chaniter);
+		r2chan = R2CALL(ftdmchan)->r2chan;
 		openr2_chan_set_blocked(r2chan);
 	}
 
+	ftdm_iterator_free(chaniter);
+	ftdm_safe_free(poll_events);
+
 	ftdm_clear_flag(r2data, FTDM_R2_RUNNING);
 	ftdm_log(FTDM_LOG_DEBUG, "R2 thread ending.\n");
 
@@ -1520,8 +1650,8 @@ static FIO_API_FUNCTION(ftdm_r2_api)
 	char *mycmd = NULL, *argv[10] = { 0 };
 	int argc = 0;
 	int span_id = 0;
-	int chan_id = 0;
-	int i = 0;
+	unsigned int chan_id = 0;
+	unsigned int i = 0;
 	ftdm_r2_data_t *r2data = NULL;
 	openr2_chan_t *r2chan = NULL;
 	openr2_context_t *r2context = NULL;
@@ -1604,7 +1734,7 @@ static FIO_API_FUNCTION(ftdm_r2_api)
 					goto done;
 				}
 				if (!(r2data =  span->signal_data)) {
-					stream->write_function(stream, "-ERR invalid span. No R2 singal data in span.\n");
+					stream->write_function(stream, "-ERR invalid span. No R2 signal data in span.\n");
 					goto done;
 				}
 				r2context = r2data->r2context;
@@ -1615,19 +1745,17 @@ static FIO_API_FUNCTION(ftdm_r2_api)
 						"Max DNIS: %d\n"
 						"ANI First: %s\n"
 						"Immediate Accept: %s\n"
-						"Side: %s\n"
+						"Job Thread: %lu\n"
 						"Job Max ms: %d\n"
-						"Job Loops: %lu\n"
-						"Monitor Thread: %lu\n",
+						"Job Loops: %lu\n",
 						openr2_proto_get_variant_string(r2variant),
 						openr2_context_get_max_ani(r2context),
 						openr2_context_get_max_dnis(r2context),
 						openr2_context_get_ani_first(r2context) ? "Yes" : "No",
 						openr2_context_get_immediate_accept(r2context) ? "Yes" : "No",
-                                                "no side",
+						r2data->monitor_thread_id,
 						r2data->jobmax, 
-						r2data->loops,
-						r2data->monitor_thread_id);
+						r2data->total_loops);
 				stream->write_function(stream, "\n");
 				stream->write_function(stream, "%4s %-12.12s %-12.12s\n", "Channel", "Tx CAS", "Rx CAS");
 				for (i = 1; i <= span->chan_count; i++) {
@@ -1646,6 +1774,39 @@ static FIO_API_FUNCTION(ftdm_r2_api)
 			}
 		}
 
+		if (!strcasecmp(argv[0], "loopstats")) {
+			int range;
+			float pct;
+			span_id = atoi(argv[1]);
+
+			if (ftdm_span_find_by_name(argv[1], &span) == FTDM_SUCCESS || ftdm_span_find(span_id, &span) == FTDM_SUCCESS) {
+				if (span->start != ftdm_r2_start) {
+					stream->write_function(stream, "-ERR not an R2 span.\n");
+					goto done;
+				}
+				if (!(r2data =  span->signal_data)) {
+					stream->write_function(stream, "-ERR invalid span. No R2 signal data in span.\n");
+					goto done;
+				}
+				range = 0;
+				for (i = 0; i < ftdm_array_len(r2data->loops); i++) {
+					pct = 100*(float)r2data->loops[i]/r2data->total_loops;
+					if ((i + 1) == ftdm_array_len(r2data->loops)) {
+						stream->write_function(stream, ">= %dms: %llu - %.03lf%%\n", range, r2data->loops[i], pct);
+					} else {
+						stream->write_function(stream, "%d-%dms: %llu - %.03lf%%\n", range, range + 9, r2data->loops[i], pct);
+					}
+					range += 10;
+				}
+				stream->write_function(stream, "\n");
+				stream->write_function(stream, "+OK.\n");
+				goto done;
+			} else {
+				stream->write_function(stream, "-ERR invalid span.\n");
+				goto done;
+			}
+		}
+
 	}
 
 	if (argc == 1) {
@@ -1735,12 +1896,13 @@ static FIO_SIG_UNLOAD_FUNCTION(ftdm_r2_destroy)
 }
 
 EX_DECLARE_DATA ftdm_module_t ftdm_module = { 
-	"r2",
-	ftdm_r2_io_init,
-	NULL,
-	ftdm_r2_init,
-	ftdm_r2_configure_span,
-	ftdm_r2_destroy
+	/* .name */ "r2",
+	/* .io_load */ ftdm_r2_io_init,
+	/* .io_unload */ NULL,
+	/* .sig_load */ ftdm_r2_init,
+	/* .sig_configure */ NULL,
+	/* .sig_unload */ ftdm_r2_destroy,
+	/* .configure_span_signaling */ ftdm_r2_configure_span_signaling
 };
 	
 

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

@@ -35,6 +35,7 @@
  * Moises Silva <moy@sangoma.com>
  * David Yat Sin <davidy@sangoma.com>
  * Nenad Corbic <ncorbic@sangoma.com>
+ * Arnaldo Pereira <arnaldo@sangoma.com>
  *
  */
 
@@ -99,7 +100,8 @@ static struct {
 /* a bunch of this stuff should go into the wanpipe_tdm_api_iface.h */
 
 FIO_SPAN_POLL_EVENT_FUNCTION(wanpipe_poll_event);
-FIO_SPAN_NEXT_EVENT_FUNCTION(wanpipe_next_event);
+FIO_SPAN_NEXT_EVENT_FUNCTION(wanpipe_span_next_event);
+FIO_CHANNEL_NEXT_EVENT_FUNCTION(wanpipe_channel_next_event);
 
 /**
  * \brief Poll for event on a wanpipe socket
@@ -794,7 +796,7 @@ static void wanpipe_write_stats(ftdm_channel_t *ftdmchan, wp_tdm_api_tx_hdr_t *t
 	/* we don't test for 80% full in tx since is typically full for voice channels, should we test tx 80% full for D-channels? */
 	if (ftdmchan->iostats.tx.queue_len >= ftdmchan->iostats.tx.queue_size) {
 		ftdm_log_chan(ftdmchan, FTDM_LOG_CRIT, "Tx Queue Full (%d/%d)\n",
-					  ftdmchan->iostats.rx.queue_len, ftdmchan->iostats.tx.queue_size);
+					  ftdmchan->iostats.tx.queue_len, ftdmchan->iostats.tx.queue_size);
 		ftdm_set_flag(&(ftdmchan->iostats.tx), FTDM_IOSTATS_ERROR_QUEUE_FULL);
 	} else if (ftdm_test_flag(&(ftdmchan->iostats.tx), FTDM_IOSTATS_ERROR_QUEUE_FULL)){
 		ftdm_log_chan(ftdmchan, FTDM_LOG_NOTICE, "Tx Queue no longer full (%d/%d)\n",
@@ -861,7 +863,6 @@ static void wanpipe_read_stats(ftdm_channel_t *ftdmchan, wp_tdm_api_rx_hdr_t *rx
 					  		ftdmchan->iostats.rx.queue_len, ftdmchan->iostats.rx.queue_size);
 		ftdm_set_flag(&(ftdmchan->iostats.rx), FTDM_IOSTATS_ERROR_QUEUE_THRES);
 	} else if (ftdm_test_flag(&(ftdmchan->iostats.rx), FTDM_IOSTATS_ERROR_QUEUE_THRES)){
-		/* any reason we have wanpipe_tdm_api_iface.h in ftmod_wanpipe/ dir? */
 		ftdm_log_chan(ftdmchan, FTDM_LOG_NOTICE, "Rx Queue length reduced 80% threshold (%d/%d)\n",
 					  		ftdmchan->iostats.rx.queue_len, ftdmchan->iostats.rx.queue_size);
 		ftdm_clear_flag(&(ftdmchan->iostats.rx), FTDM_IOSTATS_ERROR_QUEUE_THRES);
@@ -1181,13 +1182,155 @@ static FIO_GET_ALARMS_FUNCTION(wanpipe_get_alarms)
 	return FTDM_SUCCESS;
 }
 
+/**
+ * \brief Retrieves an event from a wanpipe channel
+ * \param channel Channel to retrieve event from
+ * \param event FreeTDM event to return
+ * \return Success or failure
+ */
+FIO_CHANNEL_NEXT_EVENT_FUNCTION(wanpipe_channel_next_event)
+{
+	ftdm_status_t status;
+	ftdm_oob_event_t event_id;
+	wanpipe_tdm_api_t tdm_api;
+	ftdm_span_t *span = ftdmchan->span;
+
+	if (ftdm_test_flag(ftdmchan, FTDM_CHANNEL_EVENT))
+		ftdm_clear_flag(ftdmchan, FTDM_CHANNEL_EVENT);
+
+	memset(&tdm_api, 0, sizeof(tdm_api));
+	status = sangoma_tdm_read_event(ftdmchan->sockfd, &tdm_api);
+	if (status != FTDM_SUCCESS) {
+		snprintf(span->last_error, sizeof(span->last_error), "%s", strerror(errno));
+		ftdm_log_chan(ftdmchan, FTDM_LOG_ERROR, "Failed to read event from channel: %s\n", strerror(errno));
+		return FTDM_FAIL;
+	}
+
+	ftdm_log_chan(ftdmchan, FTDM_LOG_DEBUG, "read wanpipe event %d\n", tdm_api.wp_tdm_cmd.event.wp_tdm_api_event_type);
+	switch(tdm_api.wp_tdm_cmd.event.wp_tdm_api_event_type) {
+
+	case WP_TDMAPI_EVENT_LINK_STATUS:
+		{
+			switch(tdm_api.wp_tdm_cmd.event.wp_tdm_api_event_link_status) {
+			case WP_TDMAPI_EVENT_LINK_STATUS_CONNECTED:
+				event_id = FTDM_OOB_ALARM_CLEAR;
+				break;
+			default:
+				event_id = FTDM_OOB_ALARM_TRAP;
+				break;
+			};
+		}
+		break;
+
+	case WP_TDMAPI_EVENT_RXHOOK:
+		{
+			if (ftdmchan->type == FTDM_CHAN_TYPE_FXS) {
+				event_id = tdm_api.wp_tdm_cmd.event.wp_tdm_api_event_hook_state & WP_TDMAPI_EVENT_RXHOOK_OFF ? FTDM_OOB_OFFHOOK : FTDM_OOB_ONHOOK;
+				if (event_id == FTDM_OOB_OFFHOOK) {
+					if (ftdm_test_flag(ftdmchan, FTDM_CHANNEL_FLASH)) {
+						ftdm_clear_flag_locked(ftdmchan, FTDM_CHANNEL_FLASH);
+						ftdm_clear_flag_locked(ftdmchan, FTDM_CHANNEL_WINK);
+						event_id = FTDM_OOB_FLASH;
+						goto event;
+					} else {
+						ftdm_set_flag_locked(ftdmchan, FTDM_CHANNEL_WINK);
+					}
+				} else {
+					if (ftdm_test_flag(ftdmchan, FTDM_CHANNEL_WINK)) {
+						ftdm_clear_flag_locked(ftdmchan, FTDM_CHANNEL_WINK);
+						ftdm_clear_flag_locked(ftdmchan, FTDM_CHANNEL_FLASH);
+						event_id = FTDM_OOB_WINK;
+						goto event;
+					} else {
+						ftdm_set_flag_locked(ftdmchan, FTDM_CHANNEL_FLASH);
+					}
+				}					
+				break;
+			} else {
+				wanpipe_tdm_api_t onhook_tdm_api;
+				memset(&onhook_tdm_api, 0, sizeof(onhook_tdm_api));
+				status = sangoma_tdm_txsig_onhook(ftdmchan->sockfd, &onhook_tdm_api);
+				if (status) {
+					snprintf(ftdmchan->last_error, sizeof(ftdmchan->last_error), "ONHOOK Failed");
+					return FTDM_FAIL;
+				}
+				event_id = onhook_tdm_api.wp_tdm_cmd.event.wp_tdm_api_event_hook_state & WP_TDMAPI_EVENT_RXHOOK_OFF ? FTDM_OOB_ONHOOK : FTDM_OOB_NOOP;	
+			}
+		}
+		break;
+	case WP_TDMAPI_EVENT_RING_DETECT:
+		{
+			event_id = tdm_api.wp_tdm_cmd.event.wp_tdm_api_event_ring_state == WP_TDMAPI_EVENT_RING_PRESENT ? FTDM_OOB_RING_START : FTDM_OOB_RING_STOP;
+		}
+		break;
+		/*
+		disabled this ones when configuring, we don't need them, do we?
+	case WP_TDMAPI_EVENT_RING_TRIP_DETECT:
+		{
+			event_id = tdm_api.wp_tdm_cmd.event.wp_tdm_api_event_ring_state == WP_TDMAPI_EVENT_RING_PRESENT ? FTDM_OOB_ONHOOK : FTDM_OOB_OFFHOOK;
+		}
+		break;
+		*/
+	case WP_TDMAPI_EVENT_RBS:
+		{
+			event_id = FTDM_OOB_CAS_BITS_CHANGE;
+			ftdmchan->rx_cas_bits = wanpipe_swap_bits(tdm_api.wp_tdm_cmd.event.wp_tdm_api_event_rbs_bits);
+		}
+		break;
+	case WP_TDMAPI_EVENT_DTMF:
+		{
+			char tmp_dtmf[2] = { tdm_api.wp_tdm_cmd.event.wp_tdm_api_event_dtmf_digit, 0 };
+			event_id = FTDM_OOB_NOOP;
+
+			if (tmp_dtmf[0] == 'f') {
+				ftdm_log_chan(ftdmchan, FTDM_LOG_DEBUG, "Ignoring wanpipe DTMF: %c, fax tones will be passed through!\n", tmp_dtmf[0]);
+				break;
+			}
+
+			if (tdm_api.wp_tdm_cmd.event.wp_tdm_api_event_dtmf_type == WAN_EC_TONE_PRESENT) {
+				ftdm_set_flag_locked(ftdmchan, FTDM_CHANNEL_MUTE);
+			}
+
+			if (tdm_api.wp_tdm_cmd.event.wp_tdm_api_event_dtmf_type == WAN_EC_TONE_STOP) {
+				ftdm_clear_flag_locked(ftdmchan, FTDM_CHANNEL_MUTE);
+				if (ftdm_test_flag(ftdmchan, FTDM_CHANNEL_INUSE)) {
+					ftdm_log_chan(ftdmchan, FTDM_LOG_DEBUG, "Queuing wanpipe DTMF: %c\n", tmp_dtmf[0]);
+					ftdm_channel_queue_dtmf(ftdmchan, tmp_dtmf);
+				}
+			} 
+		}
+		break;
+	case WP_TDMAPI_EVENT_ALARM:
+		{
+			ftdm_log_chan(ftdmchan, FTDM_LOG_DEBUG, "Got wanpipe alarms %d\n", tdm_api.wp_tdm_cmd.event.wp_api_event_alarm);
+			event_id = FTDM_OOB_ALARM_TRAP;
+		}
+		break;
+	default:
+		{
+			ftdm_log_chan(ftdmchan, FTDM_LOG_WARNING, "Unhandled wanpipe event %d\n", tdm_api.wp_tdm_cmd.event.wp_tdm_api_event_type);
+			event_id = FTDM_OOB_INVALID;
+		}
+		break;
+	}
+
+event:
+
+	ftdmchan->last_event_time = 0;
+	span->event_header.e_type = FTDM_EVENT_OOB;
+	span->event_header.enum_id = event_id;
+	span->event_header.channel = ftdmchan;
+	*event = &span->event_header;
+	return FTDM_SUCCESS;
+}
+
 /**
  * \brief Retrieves an event from a wanpipe span
  * \param span Span to retrieve event from
  * \param event FreeTDM event to return
  * \return Success or failure
  */
-FIO_SPAN_NEXT_EVENT_FUNCTION(wanpipe_next_event)
+FIO_SPAN_NEXT_EVENT_FUNCTION(wanpipe_span_next_event)
 {
 	uint32_t i,err;
 	ftdm_oob_event_t event_id;
@@ -1419,7 +1562,8 @@ static FIO_IO_LOAD_FUNCTION(wanpipe_init)
 	wanpipe_interface.read = wanpipe_read;
 	wanpipe_interface.write = wanpipe_write;
 	wanpipe_interface.poll_event = wanpipe_poll_event;
-	wanpipe_interface.next_event = wanpipe_next_event;
+	wanpipe_interface.next_event = wanpipe_span_next_event;
+	wanpipe_interface.channel_next_event = wanpipe_channel_next_event;
 	wanpipe_interface.channel_destroy = wanpipe_channel_destroy;
 	wanpipe_interface.get_alarms = wanpipe_get_alarms;
 	*fio = &wanpipe_interface;

libs/freetdm/src/include/freetdm.h

@@ -512,6 +512,7 @@ struct ftdm_memory_handler {
 #define FIO_SPAN_GET_SIG_STATUS_ARGS (ftdm_span_t *span, ftdm_signaling_status_t *status)
 #define FIO_SPAN_POLL_EVENT_ARGS (ftdm_span_t *span, uint32_t ms, short *poll_events)
 #define FIO_SPAN_NEXT_EVENT_ARGS (ftdm_span_t *span, ftdm_event_t **event)
+#define FIO_CHANNEL_NEXT_EVENT_ARGS (ftdm_channel_t *ftdmchan, ftdm_event_t **event)
 #define FIO_SIGNAL_CB_ARGS (ftdm_sigmsg_t *sigmsg)
 #define FIO_EVENT_CB_ARGS (ftdm_channel_t *ftdmchan, ftdm_event_t *event)
 #define FIO_CONFIGURE_SPAN_ARGS (ftdm_span_t *span, const char *str, ftdm_chan_type_t type, char *name, char *number)
@@ -543,6 +544,7 @@ typedef ftdm_status_t (*fio_span_set_sig_status_t) FIO_SPAN_SET_SIG_STATUS_ARGS;
 typedef ftdm_status_t (*fio_span_get_sig_status_t) FIO_SPAN_GET_SIG_STATUS_ARGS;
 typedef ftdm_status_t (*fio_span_poll_event_t) FIO_SPAN_POLL_EVENT_ARGS ;
 typedef ftdm_status_t (*fio_span_next_event_t) FIO_SPAN_NEXT_EVENT_ARGS ;
+typedef ftdm_status_t (*fio_channel_next_event_t) FIO_CHANNEL_NEXT_EVENT_ARGS ;
 typedef ftdm_status_t (*fio_signal_cb_t) FIO_SIGNAL_CB_ARGS ;
 typedef ftdm_status_t (*fio_event_cb_t) FIO_EVENT_CB_ARGS ;
 typedef ftdm_status_t (*fio_configure_span_t) FIO_CONFIGURE_SPAN_ARGS ;
@@ -575,6 +577,7 @@ typedef ftdm_status_t (*fio_api_t) FIO_API_ARGS ;
 #define FIO_SPAN_GET_SIG_STATUS_FUNCTION(name) ftdm_status_t name FIO_SPAN_GET_SIG_STATUS_ARGS
 #define FIO_SPAN_POLL_EVENT_FUNCTION(name) ftdm_status_t name FIO_SPAN_POLL_EVENT_ARGS
 #define FIO_SPAN_NEXT_EVENT_FUNCTION(name) ftdm_status_t name FIO_SPAN_NEXT_EVENT_ARGS
+#define FIO_CHANNEL_NEXT_EVENT_FUNCTION(name) ftdm_status_t name FIO_CHANNEL_NEXT_EVENT_ARGS
 #define FIO_SIGNAL_CB_FUNCTION(name) ftdm_status_t name FIO_SIGNAL_CB_ARGS
 #define FIO_EVENT_CB_FUNCTION(name) ftdm_status_t name FIO_EVENT_CB_ARGS
 #define FIO_CONFIGURE_SPAN_FUNCTION(name) ftdm_status_t name FIO_CONFIGURE_SPAN_ARGS
@@ -613,6 +616,7 @@ struct ftdm_io_interface {
 	fio_write_t write; /*!< Write data to the channel */
 	fio_span_poll_event_t poll_event; /*!< Poll for events on the whole span */
 	fio_span_next_event_t next_event; /*!< Retrieve an event from the span */
+	fio_channel_next_event_t channel_next_event; /*!< Retrieve an event from channel */
 	fio_api_t api; /*!< Execute a text command */
 };
 
@@ -931,6 +935,23 @@ FT_DECLARE(ftdm_status_t) ftdm_channel_add_to_group(const char* name, ftdm_chann
 /*! \brief Remove the channel from a hunt group */
 FT_DECLARE(ftdm_status_t) ftdm_channel_remove_from_group(ftdm_group_t* group, ftdm_channel_t* ftdmchan);
 
+/*! 
+ * \brief Retrieves an event from the span
+ *
+ * \note
+ * 	This function is non-reentrant and not thread-safe. 
+ * 	The event returned may be modified if the function is called again 
+ * 	from a different thread or even the same. It is recommended to
+ * 	handle events from the same span in a single thread.
+ *
+ * \param ftdmchan The channel to retrieve the event from
+ * \param event Pointer to store the pointer to the event
+ *
+ * \retval FTDM_SUCCESS success (at least one event available)
+ * \retval FTDM_FAIL failure
+ */
+FT_DECLARE(ftdm_status_t) ftdm_channel_read_event(ftdm_channel_t *ftdmchan, ftdm_event_t **event);
+
 /*! \brief Find a hunt group by id */
 FT_DECLARE(ftdm_status_t) ftdm_group_find(uint32_t id, ftdm_group_t **group);