From 573adced1f17ade41b8164d2b14f414195ca2a5e Mon Sep 17 00:00:00 2001 From: Nenad Corbic <ncorbic@sangoma.com> Date: Thu, 15 Apr 2010 11:35:37 -0400 Subject: [PATCH] Multiple updates and bug fixes to ftdm/openzap. Major stress test --- libs/freetdm/src/ftdm_io.c | 19 +- libs/freetdm/src/ftdm_threadmutex.c | 8 +- .../ftmod_sangoma_boost/ftmod_sangoma_boost.c | 307 +++++++++++++++--- .../sangoma_boost_client.c | 4 +- .../src/ftmod/ftmod_sangoma_boost/sigboost.h | 18 + .../ozmod_sangoma_boost/ozmod_sangoma_boost.c | 162 ++++++++- .../src/ozmod/ozmod_sangoma_boost/sigboost.h | 18 + 7 files changed, 467 insertions(+), 69 deletions(-) diff --git a/libs/freetdm/src/ftdm_io.c b/libs/freetdm/src/ftdm_io.c index 089e66da37..356eba5cb8 100644 --- a/libs/freetdm/src/ftdm_io.c +++ b/libs/freetdm/src/ftdm_io.c @@ -1087,16 +1087,20 @@ FT_DECLARE(ftdm_status_t) ftdm_channel_set_state(ftdm_channel_t *ftdmchan, ftdm_ } } - if (ftdm_test_flag(ftdmchan, FTDM_CHANNEL_STATE_CHANGE)) { - ftdm_log(FTDM_LOG_CRIT, "Ignored state change request from %s to %s, the previous state change has not been processed yet\n", - ftdm_channel_state2str(ftdmchan->state), ftdm_channel_state2str(state)); - return FTDM_FAIL; - } - if (lock) { ftdm_mutex_lock(ftdmchan->mutex); } + if (ftdm_test_flag(ftdmchan, FTDM_CHANNEL_STATE_CHANGE)) { + ftdm_log(FTDM_LOG_CRIT, "Ignored state change request from %s to %s, the previous state change has not been processed yet\n", + ftdm_channel_state2str(ftdmchan->state), ftdm_channel_state2str(state)); + if (lock) { + ftdm_mutex_unlock(ftdmchan->mutex); + } + return FTDM_FAIL; + } + + if (ftdmchan->span->state_map) { ok = ftdm_parse_state_map(ftdmchan, state, ftdmchan->span->state_map); goto end; @@ -1353,7 +1357,8 @@ FT_DECLARE(ftdm_status_t) ftdm_channel_open_by_span(uint32_t span_id, ftdm_direc ftdm_span_channel_use_count(span, &count); if (count >= span->chan_count) { - ftdm_log(FTDM_LOG_CRIT, "All circuits are busy.\n"); + ftdm_log(FTDM_LOG_CRIT, "All circuits are busy: active=%i max=%i.\n", + count, span->chan_count); *ftdmchan = NULL; return FTDM_FAIL; } diff --git a/libs/freetdm/src/ftdm_threadmutex.c b/libs/freetdm/src/ftdm_threadmutex.c index 9eca9eeb3d..1eb34a81f8 100644 --- a/libs/freetdm/src/ftdm_threadmutex.c +++ b/libs/freetdm/src/ftdm_threadmutex.c @@ -414,7 +414,7 @@ FT_DECLARE(ftdm_status_t) ftdm_interrupt_multiple_wait(ftdm_interrupt_t *interru for (i = 0; i < size; i++) { ints[i] = interrupts[i]->event; if (interrupts[i]->device != FTDM_INVALID_SOCKET) { - ints[i+numdevices] = interrupts[i]->device; + ints[size+numdevices] = interrupts[i]->device; numdevices++; } } @@ -446,9 +446,9 @@ FT_DECLARE(ftdm_status_t) ftdm_interrupt_multiple_wait(ftdm_interrupt_t *interru ints[i].revents = 0; ints[i].fd = interrupts[i]->readfd; if (interrupts[i]->device != FTDM_INVALID_SOCKET) { - ints[i+numdevices].events = POLLIN; - ints[i+numdevices].revents = 0; - ints[i+numdevices].fd = interrupts[i]->device; + ints[size+numdevices].events = POLLIN; + ints[size+numdevices].revents = 0; + ints[size+numdevices].fd = interrupts[i]->device; numdevices++; } } diff --git a/libs/freetdm/src/ftmod/ftmod_sangoma_boost/ftmod_sangoma_boost.c b/libs/freetdm/src/ftmod/ftmod_sangoma_boost/ftmod_sangoma_boost.c index f8e819e6d2..f7f1aac7ad 100644 --- a/libs/freetdm/src/ftmod/ftmod_sangoma_boost/ftmod_sangoma_boost.c +++ b/libs/freetdm/src/ftmod/ftmod_sangoma_boost/ftmod_sangoma_boost.c @@ -89,7 +89,6 @@ typedef uint16_t sangoma_boost_request_id_t; typedef enum { BST_FREE, BST_WAITING, - BST_ACK, BST_READY, BST_FAIL } sangoma_boost_request_status_t; @@ -106,6 +105,13 @@ typedef struct { int flags; } sangoma_boost_request_t; +typedef struct { + int call_setup_id; + int last_event_id; +} sangoma_boost_call_t; + +#define CALL_DATA(ftdmchan) ((sangoma_boost_call_t*)((ftdmchan)->call_data)) + //#define MAX_REQ_ID FTDM_MAX_PHYSICAL_SPANS_PER_LOGICAL_SPAN * FTDM_MAX_CHANNELS_PHYSICAL_SPAN #define MAX_REQ_ID 6000 @@ -132,7 +138,7 @@ static void __release_request_id_span_chan(int span, int chan, const char *func, ftdm_mutex_lock(request_mutex); if ((id = SETUP_GRID[span][chan])) { - assert(id <= MAX_REQ_ID); + ftdm_assert(id <= MAX_REQ_ID, "Invalid id"); req_map[id] = 0; SETUP_GRID[span][chan] = 0; } @@ -148,7 +154,7 @@ static void __release_request_id_span_chan(int span, int chan, const char *func, */ static void __release_request_id(sangoma_boost_request_id_t r, const char *func, int line) { - assert(r <= MAX_REQ_ID); + ftdm_assert(r <= MAX_REQ_ID, "Invalid id"); ftdm_mutex_lock(request_mutex); req_map[r] = 0; ftdm_mutex_unlock(request_mutex); @@ -176,7 +182,7 @@ static sangoma_boost_request_id_t __next_request_id(const char *func, int line) r = ++last_req; if (r >= MAX_REQ_ID) { - r = i = last_req = 1; + r = last_req = 1; } if (req_map[r]) { @@ -201,6 +207,25 @@ static sangoma_boost_request_id_t __next_request_id(const char *func, int line) } #define next_request_id() __next_request_id(__FUNCTION__, __LINE__) + +static void print_request_ids(void) +{ + sangoma_boost_request_id_t i = 0; + + ftdm_mutex_lock(request_mutex); + + for (i=1; i<= MAX_REQ_ID; i++){ + if (req_map[i]) { + ftdm_log(FTDM_LOG_CRIT, "Used Request ID=%i\n",i); + } + } + + ftdm_mutex_unlock(request_mutex); + + return; +} + + /** * \brief Finds the channel that triggered an event * \param span Span where to search the channel @@ -212,9 +237,26 @@ static ftdm_channel_t *find_ftdmchan(ftdm_span_t *span, sangomabc_short_event_t { uint32_t i; ftdm_channel_t *ftdmchan = NULL; - ftdm_sangoma_boost_data_t *sangoma_boost_data = span->signal_data; + ftdm_sangoma_boost_data_t *sangoma_boost_data; uint32_t targetspan = event->span+1; uint32_t targetchan = event->chan+1; + + /* NC: Sanity check in case the call setup id does not relate + to span. This can happen if RESTART is received on a + full load. Where stray ACK messages can arrive after + a RESTART has taken place. + */ + if (!span) { + ftdm_log(FTDM_LOG_CRIT, "No Span for Event=%s s%dc%d cid=%d\n", + BOOST_DECODE_EVENT_ID(event->event_id), + event->span, + event->chan, + event->call_setup_id); + return NULL; + } + + sangoma_boost_data = span->signal_data; + if (sangoma_boost_data->sigmod) { /* span is not strictly needed here since we're supposed to get only events for our span */ targetspan = event->span; @@ -278,12 +320,20 @@ static FIO_CHANNEL_REQUEST_FUNCTION(sangoma_boost_channel_request) * and PRI stack will retransmit a second SETUP after the first timeout, so * we should allow for at least 8 seconds. */ + int boost_request_timeout = 10000; sangoma_boost_request_status_t st; char dnis[128] = ""; char *gr = NULL; uint32_t count = 0; int tg=0; + + /* NC: On large number of calls 10 seconds is not enough. + Resetting to 30 seconds. Especially on ss7 when + links are reset during large call volume */ + if (!sangoma_boost_data->sigmod) { + boost_request_timeout = 30000; + } if (sangoma_boost_data->sigmod) { ftdm_log(FTDM_LOG_CRIT, "This function should not be called when sigmod was configured in boost\n"); @@ -292,12 +342,22 @@ static FIO_CHANNEL_REQUEST_FUNCTION(sangoma_boost_channel_request) } if (ftdm_test_flag(span, FTDM_SPAN_SUSPENDED)) { - ftdm_log(FTDM_LOG_CRIT, "SPAN is not online.\n"); + ftdm_log(FTDM_LOG_CRIT, "SPAN is Suspended.\n"); + *ftdmchan = NULL; + return FTDM_FAIL; + } + + if (check_congestion(tg)) { + ftdm_log(FTDM_LOG_CRIT, "All circuits are busy. Trunk Group=%i (CONGESTION)\n",tg+1); + *ftdmchan = NULL; + return FTDM_FAIL; + } + + if (count >= span->chan_count) { + ftdm_log(FTDM_LOG_CRIT, "All circuits are busy.\n"); *ftdmchan = NULL; return FTDM_FAIL; } - - ftdm_set_string(dnis, caller_data->dnis.digits); r = next_request_id(); if (r == 0) { @@ -305,7 +365,11 @@ static FIO_CHANNEL_REQUEST_FUNCTION(sangoma_boost_channel_request) *ftdmchan = NULL; return FTDM_FAIL; } - sangomabc_call_init(&event, caller_data->cid_num.digits, dnis, r); + + /* After this point we must release request id before we leave the function + in case of an error. */ + + ftdm_set_string(dnis, caller_data->dnis.digits); if ((gr = strchr(dnis, '@'))) { *gr++ = '\0'; @@ -317,22 +381,14 @@ static FIO_CHANNEL_REQUEST_FUNCTION(sangoma_boost_channel_request) tg--; } } + + sangomabc_call_init(&event, caller_data->cid_num.digits, dnis, r); + event.trunk_group = tg; - if (check_congestion(tg)) { - ftdm_log(FTDM_LOG_CRIT, "All circuits are busy. Trunk Group=%i (BOOST REQUESTED BACK OFF)\n",tg+1); - *ftdmchan = NULL; - return FTDM_FAIL; - } ftdm_span_channel_use_count(span, &count); - if (count >= span->chan_count) { - ftdm_log(FTDM_LOG_CRIT, "All circuits are busy.\n"); - *ftdmchan = NULL; - return FTDM_FAIL; - } - if (gr && *(gr+1)) { switch(*gr) { case 'g': @@ -375,7 +431,7 @@ static FIO_CHANNEL_REQUEST_FUNCTION(sangoma_boost_channel_request) if (sangomabc_connection_write(&sangoma_boost_data->mcon, &event) <= 0) { ftdm_log(FTDM_LOG_CRIT, "Failed to tx boost event [%s]\n", strerror(errno)); - status = FTDM_FAIL; + status = OUTBOUND_REQUESTS[r].status = FTDM_FAIL; if (!sangoma_boost_data->sigmod) { *ftdmchan = NULL; } @@ -389,7 +445,7 @@ static FIO_CHANNEL_REQUEST_FUNCTION(sangoma_boost_channel_request) if (!sangoma_boost_data->sigmod) { *ftdmchan = NULL; } - ftdm_log(FTDM_LOG_CRIT, "s%dc%d: Csid:%d Timed out waiting for boost channel request response, current status: BST_WAITING\n", (*ftdmchan)->physical_span_id, (*ftdmchan)->physical_chan_id, r); + ftdm_log(FTDM_LOG_CRIT, "Csid:%d Timed out waiting for boost channel request response, current status: BST_WAITING\n", r); goto done; } } @@ -496,6 +552,7 @@ static FIO_CHANNEL_OUTGOING_CALL_FUNCTION(sangoma_boost_outgoing_call) ftdm_log(FTDM_LOG_DEBUG, "Dialing number %s over boost channel with request id %d\n", event.called_number_digits, r); if (sangomabc_connection_write(&sangoma_boost_data->mcon, &event) <= 0) { + release_request_id(r); ftdm_log(FTDM_LOG_CRIT, "Failed to tx boost event [%s]\n", strerror(errno)); return FTDM_FAIL; } @@ -552,7 +609,12 @@ static void handle_call_start_ack(sangomabc_connection_t *mcon, sangomabc_short_ uint32_t event_span = event->span+1; uint32_t event_chan = event->chan+1; + if (nack_map[event->call_setup_id]) { + /* In this scenario outgoing call was alrady stopped + via NACK and now we are expecting an NACK_ACK. + If we receive an ACK its a race condition thus + ignor it */ return; } @@ -614,15 +676,43 @@ static void handle_call_start_ack(sangomabc_connection_t *mcon, sangomabc_short_ OUTBOUND_REQUESTS[event->call_setup_id].status = BST_READY; return; } - } + } else { + + ftdm_assert(!mcon->sigmod, "CALL STOP ACK: Invalid Sigmod Path"); + + if ((ftdmchan = find_ftdmchan(OUTBOUND_REQUESTS[event->call_setup_id].span, (sangomabc_short_event_t*)event, 1))) { + int r; + /* NC: If we get CALL START ACK and channel is in active state + then we are completely out of sync with the other end. + Treat CALL START ACK as CALL STOP and hangup the current call. + */ + + if (ftdmchan->state == FTDM_CHANNEL_STATE_UP || + ftdmchan->state == FTDM_CHANNEL_STATE_PROGRESS_MEDIA || + ftdmchan->state == FTDM_CHANNEL_STATE_PROGRESS) { + ftdm_log(FTDM_LOG_CRIT, "FTDM_CHAN STATE UP/PROG/PROG_MEDIA -> Changed to HANGUP %d:%d\n", event->span+1,event->chan+1); + ftdm_set_state_r(ftdmchan, FTDM_CHANNEL_STATE_HANGUP, 0, r); + + } else if (ftdm_test_sflag(ftdmchan, SFLAG_HANGUP)) { + /* Do nothing because outgoing STOP will generaate a stop ack */ + + } else { + ftdm_log(FTDM_LOG_CRIT, "FTDM_CHAN STATE INVALID %s on IN CALL ACK %d:%d\n", ftdm_channel_state2str(ftdmchan->state),event->span+1,event->chan+1); + + } + ftdmchan=NULL; + } + } + if (!ftdmchan) { ftdm_log(FTDM_LOG_CRIT, "START ACK CANT FIND A CHAN %d:%d\n", event->span+1,event->chan+1); } else { /* only reason to be here is failed to open channel when we we're in sigmod */ ftdm_set_state_locked(ftdmchan, FTDM_CHANNEL_STATE_TERMINATING); + ftdm_set_sflag(ftdmchan, SFLAG_SENT_FINAL_MSG); } - ftdm_set_sflag(ftdmchan, SFLAG_SENT_FINAL_MSG); + sangomabc_exec_command(mcon, event->span, event->chan, @@ -643,7 +733,7 @@ static void handle_call_done(ftdm_span_t *span, sangomabc_connection_t *mcon, sa { ftdm_channel_t *ftdmchan; int r = 0; - + if ((ftdmchan = find_ftdmchan(span, event, 1))) { ftdm_sangoma_boost_data_t *sangoma_boost_data = ftdmchan->span->signal_data; ftdm_mutex_lock(ftdmchan->mutex); @@ -684,6 +774,7 @@ static void handle_call_done(ftdm_span_t *span, sangomabc_connection_t *mcon, sa } } + /** * \brief Handler for call start nack event * \param span Span where event was fired @@ -725,7 +816,7 @@ static void handle_call_start_nack(ftdm_span_t *span, sangomabc_connection_t *mc if (event->call_setup_id) { if (sangoma_boost_data->sigmod) { ftdmchan = OUTBOUND_REQUESTS[event->call_setup_id].ftdmchan; - ftdmchan->call_data = (void*)(intptr_t)event->event_id; + CALL_DATA(ftdmchan)->last_event_id = event->event_id; ftdm_set_state_locked(ftdmchan, FTDM_CHANNEL_STATE_TERMINATING); } else { sangomabc_exec_command(mcon, @@ -747,7 +838,7 @@ static void handle_call_start_nack(ftdm_span_t *span, sangomabc_connection_t *mc /* if there is no call setup id this should not be an outbound channel for sure */ ftdm_assert(!ftdm_test_flag(ftdmchan, FTDM_CHANNEL_OUTBOUND), "Yay, outbound flag should not be set here!\n"); - ftdmchan->call_data = (void*)(intptr_t)event->event_id; + CALL_DATA(ftdmchan)->last_event_id = event->event_id; ftdm_mutex_lock(ftdmchan->mutex); ftdm_set_state_r(ftdmchan, FTDM_CHANNEL_STATE_TERMINATING, 0, r); if (r == FTDM_STATE_CHANGE_SUCCESS) { @@ -800,7 +891,16 @@ static void handle_call_stop(ftdm_span_t *span, sangomabc_connection_t *mcon, sa ftdm_mutex_lock(ftdmchan->mutex); - if (ftdm_test_sflag(ftdmchan, SFLAG_HANGUP)) { + if (ftdm_test_sflag(ftdmchan, SFLAG_HANGUP) || + ftdmchan->state == FTDM_CHANNEL_STATE_DOWN || + ftdmchan->state == FTDM_CHANNEL_STATE_TERMINATING) { + + /* NC: Checking for state DOWN because ss7box can + send CALL_STOP twice in a row. If we do not check for + STATE_DOWN we will set the state back to termnating + and block the channel forever + */ + /* racing condition where both sides initiated a hangup * Do not change current state as channel is already clearing * itself through local initiated hangup */ @@ -855,8 +955,18 @@ static void handle_call_answer(ftdm_span_t *span, sangomabc_connection_t *mcon, if ((ftdmchan = find_ftdmchan(span, event, 1))) { ftdm_mutex_lock(ftdmchan->mutex); - if (ftdmchan->state == FTDM_CHANNEL_STATE_HOLD) { + + if (ftdm_test_sflag(ftdmchan, SFLAG_HANGUP) || + ftdmchan->state == FTDM_CHANNEL_STATE_DOWN || + ftdmchan->state == FTDM_CHANNEL_STATE_TERMINATING) { + + /* NC: Do nothing here because we are in process + of stopping the call. So ignore the ANSWER. */ + ftdm_log(FTDM_LOG_CRIT, "ANSWER BUT CALL IS HANGUP %d:%d\n", event->span+1,event->chan+1); + + } else if (ftdmchan->state == FTDM_CHANNEL_STATE_HOLD) { ftdmchan->init_state = FTDM_CHANNEL_STATE_UP; + } else { int r = 0; ftdm_set_state_r(ftdmchan, FTDM_CHANNEL_STATE_UP, 0, r); @@ -888,6 +998,12 @@ static void handle_call_start(ftdm_span_t *span, sangomabc_connection_t *mcon, s if (!(ftdmchan = find_ftdmchan(span, (sangomabc_short_event_t*)event, 0))) { if ((ftdmchan = find_ftdmchan(span, (sangomabc_short_event_t*)event, 1))) { int r; + + /* NC: If we get CALL START and channel is in active state + then we are completely out of sync with the other end. + Treat CALL START as CALL STOP and hangup the current call. + */ + if (ftdmchan->state == FTDM_CHANNEL_STATE_UP) { ftdm_log(FTDM_LOG_CRIT, "ZCHAN STATE UP -> Changed to TERMINATING %d:%d\n", event->span+1,event->chan+1); ftdm_set_state_r(ftdmchan, FTDM_CHANNEL_STATE_TERMINATING, 0, r); @@ -1186,8 +1302,12 @@ static int parse_sangoma_event(ftdm_span_t *span, sangomabc_connection_t *mcon, handle_call_done(span, mcon, event); break; case SIGBOOST_EVENT_CALL_START_NACK_ACK: - handle_call_done(span, mcon, event); - nack_map[event->call_setup_id] = 0; + /* On NACK ack span chan are always invalid + All there is to do is to clear the id */ + if (event->call_setup_id) { + nack_map[event->call_setup_id] = 0; + release_request_id(event->call_setup_id); + } break; case SIGBOOST_EVENT_INSERT_CHECK_LOOP: handle_call_loop_start(span, mcon, event); @@ -1253,7 +1373,7 @@ static __inline__ void state_advance(ftdm_channel_t *ftdmchan) if (!ftdm_test_sflag(ftdmchan, SFLAG_SENT_FINAL_MSG)) { ftdm_set_sflag_locked(ftdmchan, SFLAG_SENT_FINAL_MSG); - if (ftdmchan->call_data && ((uint32_t)(intptr_t)ftdmchan->call_data == SIGBOOST_EVENT_CALL_START_NACK)) { + if (ftdmchan->call_data && CALL_DATA(ftdmchan)->last_event_id == SIGBOOST_EVENT_CALL_START_NACK) { sangomabc_exec_command(mcon, BOOST_SPAN(ftdmchan), BOOST_CHAN(ftdmchan), @@ -1273,7 +1393,8 @@ static __inline__ void state_advance(ftdm_channel_t *ftdmchan) } } ftdmchan->sflags = 0; - ftdmchan->call_data = NULL; + memset(ftdmchan->call_data,0,sizeof(sangoma_boost_call_t)); + if (sangoma_boost_data->sigmod && call_stopped_ack_sent) { /* we dont want to call ftdm_channel_done just yet until call released is received */ ftdm_log(FTDM_LOG_DEBUG, "Waiting for call release confirmation before declaring chan %d:%d as available \n", @@ -1464,13 +1585,17 @@ static __inline__ void check_state(ftdm_span_t *span) uint32_t j; ftdm_clear_flag_locked(span, FTDM_SPAN_STATE_CHANGE); if (susp) { - for (j = 0; j <= span->chan_count; j++) { - ftdm_mutex_lock(span->channels[j]->mutex); - ftdm_clear_flag((span->channels[j]), FTDM_CHANNEL_STATE_CHANGE); - ftdm_channel_set_state(span->channels[j], FTDM_CHANNEL_STATE_RESTART, 0); - state_advance(span->channels[j]); - ftdm_channel_complete_state(span->channels[j]); - ftdm_mutex_unlock(span->channels[j]->mutex); + for(j = 1; j <= span->chan_count; j++) { + if (ftdm_test_flag((span->channels[j]), FTDM_CHANNEL_STATE_CHANGE) || susp) { + ftdm_mutex_lock(span->channels[j]->mutex); + ftdm_clear_flag((span->channels[j]), FTDM_CHANNEL_STATE_CHANGE); + if (susp && span->channels[j]->state != FTDM_CHANNEL_STATE_DOWN) { + ftdm_channel_set_state(span->channels[j], FTDM_CHANNEL_STATE_RESTART, 0); + } + state_advance(span->channels[j]); + ftdm_channel_complete_state(span->channels[j]); + ftdm_mutex_unlock(span->channels[j]->mutex); + } } } else { while ((ftdmchan = ftdm_queue_dequeue(span->pendingchans))) { @@ -1649,8 +1774,8 @@ static int ftdm_boost_wait_event(ftdm_span_t *span) sangoma_boost_data->iteration = 0; } #endif - res = ftdm_interrupt_multiple_wait(ints, numints, -1); - if (FTDM_SUCCESS != res) { + res = ftdm_interrupt_multiple_wait(ints, numints, 100); + if (FTDM_SUCCESS != res && FTDM_TIMEOUT != res) { ftdm_log(FTDM_LOG_CRIT, "Unexpected return value from interrupt waiting: %d\n", res); return -1; } @@ -1737,7 +1862,6 @@ static void *ftdm_sangoma_boost_run(ftdm_thread_t *me, void *obj) if (ftdm_boost_wait_event(span) < 0) { ftdm_log(FTDM_LOG_ERROR, "ftdm_boost_wait_event failed\n"); - goto error; } while ((event = ftdm_boost_read_event(span))) { @@ -1750,7 +1874,6 @@ static void *ftdm_sangoma_boost_run(ftdm_thread_t *me, void *obj) goto end; -error: ftdm_log(FTDM_LOG_CRIT, "Boost event processing Error!\n"); end: @@ -1765,6 +1888,37 @@ end: return NULL; } +#if 0 +static int sigmod_ss7box_isup_exec_cmd(ftdm_stream_handle_t *stream, char *cmd) +{ + FILE *fp; + int status=0; + char path[1024]; + + fp = popen(cmd, "r"); + if (fp == NULL) { + stream->write_function(stream, "%s: -ERR failed to execute cmd: %s\n", + __FILE__,cmd); + return -1; + } + + while (fgets(path, sizeof(path)-1, fp) != NULL) { + path[sizeof(path)-1]='\0'; + stream->write_function(stream,"%s", path); + } + + + status = pclose(fp); + if (status == -1) { + /* Error reported by pclose() */ + } else { + /* Use macros described under wait() to inspect `status' in order + to determine success/failure of command executed by popen() */ + } + + return status; +} +#endif #define FTDM_BOOST_SYNTAX "list sigmods | <sigmod_name> <command>" /** @@ -1787,11 +1941,63 @@ static FIO_API_FUNCTION(ftdm_sangoma_boost_api) if (!strcasecmp(argv[0], "list")) { if (!strcasecmp(argv[1], "sigmods")) { if (ftdm_sangoma_boost_list_sigmods(stream) != FTDM_SUCCESS) { - stream->write_function(stream, "%s: -ERR failed to execute cmd\n", __FILE__); + stream->write_function(stream, "-ERR failed to list sigmods\n"); goto done; } goto done; } + + if (!strcasecmp(argv[1], "ids")) { + print_request_ids(); + goto done; + } + +#ifndef __WINDOWS__ +#if 0 +/* NC: This code crashes the kernel due to fork on heavy fs load */ + } else if (!strcasecmp(argv[0], "ss7box_isupd_ckt")) { + + if (!strcasecmp(argv[1], "used")) { + stream->write_function(stream, "ss7box_isupd: in use\n", FTDM_BOOST_SYNTAX); + sigmod_ss7box_isup_exec_cmd(stream, (char*) "ckt_report.sh inuse"); + } else if (!strcasecmp(argv[1], "reset")) { + stream->write_function(stream, "ss7box_isupd: in reset\n", FTDM_BOOST_SYNTAX); + sigmod_ss7box_isup_exec_cmd(stream, (char*) "ckt_report.sh reset"); + } else if (!strcasecmp(argv[1], "ready")) { + stream->write_function(stream, "ss7box_isupd: ready \n", FTDM_BOOST_SYNTAX); + sigmod_ss7box_isup_exec_cmd(stream, (char*) "ckt_report.sh free"); + } else { + stream->write_function(stream, "ss7box_isupd: list\n", FTDM_BOOST_SYNTAX); + sigmod_ss7box_isup_exec_cmd(stream, (char*) "ckt_report.sh"); + } + + goto done; +#endif +#endif + } else if (!strcasecmp(argv[0], "restart")) { + sangomabc_connection_t *pcon; + ftdm_sangoma_boost_data_t *sangoma_boost_data; + ftdm_span_t *span; + int err = ftdm_span_find_by_name(argv[1], &span); + if (FTDM_SUCCESS != err) { + stream->write_function(stream, "-ERR failed to find span by name %s\n",argv[1]); + goto done; + } + + sangoma_boost_data = span->signal_data; + pcon = &sangoma_boost_data->pcon; + + /* No need to set any span flags because + our RESTART will generate a RESTART from the sig daemon */ + sangomabc_exec_commandp(pcon, + 0, + 0, + -1, + SIGBOOST_EVENT_SYSTEM_RESTART, + 0); + + goto done; + } else { boost_sigmod_interface_t *sigmod_iface = NULL; sigmod_iface = hashtable_search(g_boost_modules_hash, argv[0]); @@ -1829,7 +2035,7 @@ done: */ static FIO_IO_LOAD_FUNCTION(ftdm_sangoma_boost_io_init) { - assert(fio != NULL); + ftdm_assert(fio != NULL, "fio is NULL"); memset(&ftdm_sangoma_boost_interface, 0, sizeof(ftdm_sangoma_boost_interface)); ftdm_sangoma_boost_interface.name = "boost"; @@ -2212,6 +2418,7 @@ static FIO_CONFIGURE_SPAN_SIGNALING_FUNCTION(ftdm_sangoma_boost_configure_span) ftdm_dso_lib_t lib = NULL; char path[255] = ""; char *err = NULL; + int j = 0; unsigned paramindex = 0; ftdm_status_t rc = FTDM_SUCCESS; @@ -2306,6 +2513,14 @@ static FIO_CONFIGURE_SPAN_SIGNALING_FUNCTION(ftdm_sangoma_boost_configure_span) ftdm_set_string(sangoma_boost_data->mcon.cfg.remote_ip, remote_ip); sangoma_boost_data->mcon.cfg.remote_port = remote_port; } + + for (j = 1; j <= span->chan_count; j++) { + span->channels[j]->call_data = ftdm_calloc(1,sizeof(sangoma_boost_call_t)); + if (!span->channels[j]->call_data) { + FAIL_CONFIG_RETURN(FTDM_FAIL); + } + } + span->signal_cb = sig_cb; span->start = ftdm_sangoma_boost_start; span->stop = ftdm_sangoma_boost_stop; diff --git a/libs/freetdm/src/ftmod/ftmod_sangoma_boost/sangoma_boost_client.c b/libs/freetdm/src/ftmod/ftmod_sangoma_boost/sangoma_boost_client.c index c5cb97119f..b2a38b198d 100644 --- a/libs/freetdm/src/ftmod/ftmod_sangoma_boost/sangoma_boost_client.c +++ b/libs/freetdm/src/ftmod/ftmod_sangoma_boost/sangoma_boost_client.c @@ -77,7 +77,7 @@ static void sangomabc_print_event_call(sangomabc_connection_t *mcon, sangomabc_e if (event->event_id == SIGBOOST_EVENT_HEARTBEAT) return; - ftdm_log(file, func, line, FTDM_LOG_LEVEL_DEBUG, "%s EVENT (%s): %s:(%X) [w%dg%d] CSid=%i Seq=%i Cn=[%s] Cd=[%s] Ci=[%s] Rdnis=[%s]\n", + ftdm_log(file, func, line, FTDM_LOG_LEVEL_WARNING, "%s EVENT (%s): %s:(%X) [w%dg%d] CSid=%i Seq=%i Cn=[%s] Cd=[%s] Ci=[%s] Rdnis=[%s]\n", dir ? "TX":"RX", priority ? "P":"N", sangomabc_event_id_name(event->event_id), @@ -96,7 +96,7 @@ static void sangomabc_print_event_short(sangomabc_connection_t *mcon, sangomabc_ { if (event->event_id == SIGBOOST_EVENT_HEARTBEAT) return; - ftdm_log(file, func, line, FTDM_LOG_LEVEL_DEBUG, "%s EVENT (%s): %s:(%X) [s%dc%d] Rc=%i CSid=%i Seq=%i \n", + ftdm_log(file, func, line, FTDM_LOG_LEVEL_WARNING, "%s EVENT (%s): %s:(%X) [s%dc%d] Rc=%i CSid=%i Seq=%i \n", dir ? "TX":"RX", priority ? "P":"N", sangomabc_event_id_name(event->event_id), diff --git a/libs/freetdm/src/ftmod/ftmod_sangoma_boost/sigboost.h b/libs/freetdm/src/ftmod/ftmod_sangoma_boost/sigboost.h index 05ca52a487..7975dc5b93 100644 --- a/libs/freetdm/src/ftmod/ftmod_sangoma_boost/sigboost.h +++ b/libs/freetdm/src/ftmod/ftmod_sangoma_boost/sigboost.h @@ -51,6 +51,24 @@ enum e_sigboost_event_id_values SIGBOOST_EVENT_AUTO_CALL_GAP_ABATE = 0x8c, /*140*/ SIGBOOST_EVENT_DIGIT_IN = 0x8d, /*141*/ }; + +#define BOOST_DECODE_EVENT_ID(id) \ + (id==SIGBOOST_EVENT_CALL_START)?"SIGBOOST_EVENT_CALL_START": \ + (id==SIGBOOST_EVENT_CALL_START_ACK)?"SIGBOOST_EVENT_CALL_START_ACK": \ + (id==SIGBOOST_EVENT_CALL_START_NACK)?"SIGBOOST_EVENT_CALL_START_NACK": \ + (id==SIGBOOST_EVENT_CALL_ANSWERED)?"SIGBOOST_EVENT_CALL_ANSWERED": \ + (id==SIGBOOST_EVENT_CALL_STOPPED)?"SIGBOOST_EVENT_CALL_STOPPED": \ + (id==SIGBOOST_EVENT_CALL_STOPPED_ACK)?"SIGBOOST_EVENT_CALL_STOPPED_ACK": \ + (id==SIGBOOST_EVENT_SYSTEM_RESTART)?"SIGBOOST_EVENT_SYSTEM_RESTART": \ + (id==SIGBOOST_EVENT_SYSTEM_RESTART_ACK)?"SIGBOOST_EVENT_SYSTEM_RESTART_ACK": \ + (id==SIGBOOST_EVENT_CALL_RELEASED)?"SIGBOOST_EVENT_CALL_RELEASED": \ + (id==SIGBOOST_EVENT_CALL_PROGRESS)?"SIGBOOST_EVENT_CALL_PROGRESS": \ + (id==SIGBOOST_EVENT_HEARTBEAT)?"SIGBOOST_EVENT_HEARTBEAT": \ + (id==SIGBOOST_EVENT_INSERT_CHECK_LOOP)?"SIGBOOST_EVENT_INSERT_CHECK_LOOP": \ + (id==SIGBOOST_EVENT_REMOVE_CHECK_LOOP)?"SIGBOOST_EVENT_REMOVE_CHECK_LOOP": \ + (id==SIGBOOST_EVENT_AUTO_CALL_GAP_ABATE)?"SIGBOOST_EVENT_AUTO_CALL_GAP_ABATE": \ + (id==SIGBOOST_EVENT_DIGIT_IN)?"SIGBOOST_EVENT_DIGIT_IN": "Unknown" + enum e_sigboost_release_cause_values { SIGBOOST_RELEASE_CAUSE_UNDEFINED = 0, diff --git a/libs/openzap/src/ozmod/ozmod_sangoma_boost/ozmod_sangoma_boost.c b/libs/openzap/src/ozmod/ozmod_sangoma_boost/ozmod_sangoma_boost.c index 5e0e32d9ee..995d943552 100644 --- a/libs/openzap/src/ozmod/ozmod_sangoma_boost/ozmod_sangoma_boost.c +++ b/libs/openzap/src/ozmod/ozmod_sangoma_boost/ozmod_sangoma_boost.c @@ -32,11 +32,14 @@ */ #include "openzap.h" -#include "sangoma_boost_client.h" +#include "sangoma_boost_client.h" #include "zap_sangoma_boost.h" #ifdef HAVE_SYS_SELECT_H #include <sys/select.h> #endif +#ifndef __WINDOWS__ +#include <poll.h> +#endif #define MAX_TRUNK_GROUPS 64 static time_t congestion_timeouts[MAX_TRUNK_GROUPS]; @@ -484,7 +487,31 @@ static void handle_call_start_ack(sangomabc_connection_t *mcon, sangomabc_short_ OUTBOUND_REQUESTS[event->call_setup_id].status = BST_READY; return; } - } + } else { + if ((zchan = find_zchan(OUTBOUND_REQUESTS[event->call_setup_id].span, (sangomabc_short_event_t*)event, 1))) { + int r; + + /* NC: If we get CALL START ACK and channel is in active state + then we are completely out of sync with the other end. + Treat CALL START ACK as CALL STOP and hangup the current call. + */ + + if (zchan->state == ZAP_CHANNEL_STATE_UP || + zchan->state == ZAP_CHANNEL_STATE_PROGRESS_MEDIA || + zchan->state == ZAP_CHANNEL_STATE_PROGRESS) { + zap_log(ZAP_LOG_CRIT, "ZCHAN STATE UP/PROG/PROG_MEDIA -> Changed to HANGUP %d:%d\n", event->span+1,event->chan+1); + zap_set_state_r(zchan, ZAP_CHANNEL_STATE_HANGUP, 0, r); + + } else if (zap_test_sflag(zchan, SFLAG_HANGUP)) { + /* Do nothing because outgoing STOP will generaate a stop ack */ + + } else { + zap_log(ZAP_LOG_CRIT, "ZCHAN STATE INVALID %s on IN CALL ACK %d:%d\n", zap_channel_state2str(zchan->state),event->span+1,event->chan+1); + + } + zchan=NULL; + } + } //printf("WTF BAD ACK CSid=%d span=%d chan=%d\n", event->call_setup_id, event->span+1,event->chan+1); if ((zchan = find_zchan(OUTBOUND_REQUESTS[event->call_setup_id].span, event, 1))) { @@ -640,7 +667,14 @@ static void handle_call_stop(zap_span_t *span, sangomabc_connection_t *mcon, san zap_mutex_lock(zchan->mutex); - if (zap_test_sflag(zchan, SFLAG_HANGUP)) { + if (zap_test_sflag(zchan, SFLAG_HANGUP) || zchan->state == ZAP_CHANNEL_STATE_DOWN) { + + /* NC: Checking for state DOWN because ss7box can + send CALL_STOP twice in a row. If we do not check for + STATE_DOWN we will set the state back to termnating + and block the channel forever + */ + /* racing condition where both sides initiated a hangup * Do not change current state as channel is already clearing * itself through local initiated hangup */ @@ -697,7 +731,14 @@ static void handle_call_answer(zap_span_t *span, sangomabc_connection_t *mcon, s if ((zchan = find_zchan(span, event, 1))) { zap_mutex_lock(zchan->mutex); - if (zchan->state == ZAP_CHANNEL_STATE_HOLD) { + if (zap_test_sflag(zchan, SFLAG_HANGUP) || + zchan->state == ZAP_CHANNEL_STATE_DOWN || + zchan->state == ZAP_CHANNEL_STATE_TERMINATING) { + /* NC: Do nothing here because we are in process + of stopping the call. So ignore the ANSWER. */ + zap_log(ZAP_LOG_CRIT, "ANSWER BUT CALL IS HANGUP %d:%d\n", event->span+1,event->chan+1); + + } else if (zchan->state == ZAP_CHANNEL_STATE_HOLD) { zchan->init_state = ZAP_CHANNEL_STATE_UP; } else { int r = 0; @@ -731,6 +772,12 @@ static void handle_call_start(zap_span_t *span, sangomabc_connection_t *mcon, sa if (!(zchan = find_zchan(span, (sangomabc_short_event_t*)event, 0))) { if ((zchan = find_zchan(span, (sangomabc_short_event_t*)event, 1))) { int r; + + /* NC: If we get CALL START and channel is in active state + then we are completely out of sync with the other end. + Treat CALL START as CALL STOP and hangup the current call. + */ + if (zchan->state == ZAP_CHANNEL_STATE_UP) { zap_log(ZAP_LOG_CRIT, "ZCHAN STATE UP -> Changed to TERMINATING %d:%d\n", event->span+1,event->chan+1); zap_set_state_r(zchan, ZAP_CHANNEL_STATE_TERMINATING, 0, r); @@ -1380,6 +1427,65 @@ static void *zap_sangoma_events_run(zap_thread_t *me, void *obj) return NULL; } + +#ifndef __WINDOWS__ +static int waitfor_2sockets(int fda, int fdb, char *a, char *b, int timeout) +{ + struct pollfd pfds[2]; + int res = 0; + int errflags = (POLLERR | POLLHUP | POLLNVAL); + + if (fda < 0 || fdb < 0) { + return -1; + } + + +waitfor_2sockets_tryagain: + + *a=0; + *b=0; + + + memset(pfds, 0, sizeof(pfds)); + + pfds[0].fd = fda; + pfds[1].fd = fdb; + pfds[0].events = POLLIN | errflags; + pfds[1].events = POLLIN | errflags; + + res = poll(pfds, 2, timeout); + + if (res > 0) { + res = 1; + if ((pfds[0].revents & errflags) || (pfds[1].revents & errflags)) { + res = -1; + } else { + if ((pfds[0].revents & POLLIN)) { + *a=1; + res++; + } + if ((pfds[1].revents & POLLIN)) { + *b=1; + res++; + } + } + + if (res == 1) { + /* No event found what to do */ + res=-1; + } + } else if (res < 0) { + + if (errno == EINTR || errno == EAGAIN) { + goto waitfor_2sockets_tryagain; + } + + } + + return res; +} +#endif + /** * \brief Main thread function for sangoma boost span (monitor) * \param me Current thread @@ -1391,7 +1497,13 @@ static void *zap_sangoma_boost_run(zap_thread_t *me, void *obj) zap_sangoma_boost_data_t *sangoma_boost_data = span->signal_data; sangomabc_connection_t *mcon, *pcon; uint32_t ms = 10; //, too_long = 20000; - + int max, activity, i; + sangomabc_event_t *event; + struct timeval tv; + fd_set rfds, efds; +#ifndef __WINDOWS__ + char a=0,b=0; +#endif sangoma_boost_data->pcon = sangoma_boost_data->mcon; @@ -1427,10 +1539,13 @@ static void *zap_sangoma_boost_run(zap_thread_t *me, void *obj) zap_set_flag(mcon, MSU_FLAG_DOWN); while (zap_test_flag(sangoma_boost_data, ZAP_SANGOMA_BOOST_RUNNING)) { - fd_set rfds, efds; - struct timeval tv = { 0, ms * 1000 }; - int max, activity, i = 0; - sangomabc_event_t *event = NULL; + + tv.tv_sec = 0; + tv.tv_usec = ms* 1000; + max=0; + activity=0; + i=0; + event = NULL; if (!zap_running()) { sangomabc_exec_commandp(pcon, @@ -1451,7 +1566,8 @@ static void *zap_sangoma_boost_run(zap_thread_t *me, void *obj) FD_SET(pcon->socket, &efds); max = ((pcon->socket > mcon->socket) ? pcon->socket : mcon->socket) + 1; - + +#ifdef __WINDOWS__ if ((activity = select(max, &rfds, NULL, &efds, &tv)) < 0) { goto error; } @@ -1477,7 +1593,33 @@ static void *zap_sangoma_boost_run(zap_thread_t *me, void *obj) } } +#else + a=0; + b=0; + i=0; + tv.tv_sec=0; + activity = waitfor_2sockets(pcon->socket,mcon->socket,&a,&b,ms); + if (activity) { + if (a) { + while ((event = sangomabc_connection_readp(pcon, i))) { + parse_sangoma_event(span, pcon, (sangomabc_short_event_t*)event); + i++; + } + } + i=0; + + if (b) { + if ((event = sangomabc_connection_read(mcon, i))) { + parse_sangoma_event(span, mcon, (sangomabc_short_event_t*)event); + i++; + } + } + } else if (activity < 0) { + goto error; + } + +#endif pcon->hb_elapsed += ms; diff --git a/libs/openzap/src/ozmod/ozmod_sangoma_boost/sigboost.h b/libs/openzap/src/ozmod/ozmod_sangoma_boost/sigboost.h index 1281069536..7522ea7db4 100644 --- a/libs/openzap/src/ozmod/ozmod_sangoma_boost/sigboost.h +++ b/libs/openzap/src/ozmod/ozmod_sangoma_boost/sigboost.h @@ -57,6 +57,24 @@ enum e_sigboost_event_id_values SIGBOOST_EVENT_AUTO_CALL_GAP_ABATE = 0x8c, /*140*/ SIGBOOST_EVENT_DIGIT_IN = 0x8d, /*141*/ }; + +#define BOOST_DECODE_EVENT_ID(id) \ + (id==SIGBOOST_EVENT_CALL_START)?"SIGBOOST_EVENT_CALL_START": \ + (id==SIGBOOST_EVENT_CALL_START_ACK)?"SIGBOOST_EVENT_CALL_START_ACK": \ + (id==SIGBOOST_EVENT_CALL_START_NACK)?"SIGBOOST_EVENT_CALL_START_NACK": \ + (id==SIGBOOST_EVENT_CALL_ANSWERED)?"SIGBOOST_EVENT_CALL_ANSWERED": \ + (id==SIGBOOST_EVENT_CALL_STOPPED)?"SIGBOOST_EVENT_CALL_STOPPED": \ + (id==SIGBOOST_EVENT_CALL_STOPPED_ACK)?"SIGBOOST_EVENT_CALL_STOPPED_ACK": \ + (id==SIGBOOST_EVENT_SYSTEM_RESTART)?"SIGBOOST_EVENT_SYSTEM_RESTART": \ + (id==SIGBOOST_EVENT_SYSTEM_RESTART_ACK)?"SIGBOOST_EVENT_SYSTEM_RESTART_ACK": \ + (id==SIGBOOST_EVENT_CALL_RELEASED)?"SIGBOOST_EVENT_CALL_RELEASED": \ + (id==SIGBOOST_EVENT_CALL_PROGRESS)?"SIGBOOST_EVENT_CALL_PROGRESS": \ + (id==SIGBOOST_EVENT_HEARTBEAT)?"SIGBOOST_EVENT_HEARTBEAT": \ + (id==SIGBOOST_EVENT_INSERT_CHECK_LOOP)?"SIGBOOST_EVENT_INSERT_CHECK_LOOP": \ + (id==SIGBOOST_EVENT_REMOVE_CHECK_LOOP)?"SIGBOOST_EVENT_REMOVE_CHECK_LOOP": \ + (id==SIGBOOST_EVENT_AUTO_CALL_GAP_ABATE)?"SIGBOOST_EVENT_AUTO_CALL_GAP_ABATE": \ + (id==SIGBOOST_EVENT_DIGIT_IN)?"SIGBOOST_EVENT_DIGIT_IN": "Unknown" + enum e_sigboost_release_cause_values { SIGBOOST_RELEASE_CAUSE_UNDEFINED = 0,