kenmirrors
/
freeswitch
mirror of https://github.com/signalwire/freeswitch.git
1
0
Fork 0
Code Issues Projects Releases Wiki Activity

FS-3002: handle 2833 in do_flush instead of dropping valid dtmf

This commit is contained in:
Michael Jerris 2011-01-21 16:03:19 -05:00
parent 3dd9d5c0a3
commit 3fa3e11ca2
2 changed files with 245 additions and 166 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
src/switch_apr.c
View File

@ -833,7 +833,7 @@ SWITCH_DECLARE(switch_status_t) switch_socket_recvfrom(switch_sockaddr_t *from,
*/
}
if (r == 35) {
if (r == 35 || r == 730035) {
r = SWITCH_STATUS_BREAK;
}

407
src/switch_rtp.c
View File

@ -32,6 +32,7 @@
*/
//#define DEBUG_2833
//#define RTP_DEBUG_WRITE_DELTA
//#define DEBUG_MISSED_SEQ
#include <switch.h>
#include <switch_stun.h>
#undef PACKAGE_NAME
@ -245,6 +246,9 @@ struct switch_rtp {
switch_time_t send_time;
switch_byte_t auto_adj_used;
uint8_t pause_jb;
uint16_t last_seq;
switch_time_t last_read_time;
switch_size_t last_flush_packet_count;
};
struct switch_rtcp_senderinfo {
@ -256,6 +260,180 @@ struct switch_rtcp_senderinfo {
unsigned oc:32;
};
typedef enum {
RESULT_CONTINUE,
RESULT_GOTO_END,
RESULT_GOTO_RECVFROM,
RESULT_GOTO_TIMERCHECK
} handle_rfc2833_result_t;
static handle_rfc2833_result_t handle_rfc2833(switch_rtp_t *rtp_session, switch_size_t bytes, int *do_cng)
{
#ifdef DEBUG_2833
if (rtp_session->dtmf_data.in_digit_sanity && !(rtp_session->dtmf_data.in_digit_sanity % 100)) {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "sanity %d\n", rtp_session->dtmf_data.in_digit_sanity);
}
#endif
if (rtp_session->dtmf_data.in_digit_sanity && !--rtp_session->dtmf_data.in_digit_sanity) {
rtp_session->dtmf_data.last_digit = 0;
rtp_session->dtmf_data.in_digit_ts = 0;
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed DTMF sanity check.\n");
}
/* RFC2833 ... like all RFC RE: VoIP, guaranteed to drive you to insanity!
We know the real rules here, but if we enforce them, it's an interop nightmare so,
we put up with as much as we can so we don't have to deal with being punished for
doing it right. Nice guys finish last!
*/
if (bytes > rtp_header_len && !switch_test_flag(rtp_session, SWITCH_RTP_FLAG_PROXY_MEDIA) &&
!switch_test_flag(rtp_session, SWITCH_RTP_FLAG_PASS_RFC2833) && rtp_session->recv_te && rtp_session->recv_msg.header.pt == rtp_session->recv_te) {
switch_size_t len = bytes - rtp_header_len;
unsigned char *packet = (unsigned char *) rtp_session->recv_msg.body;
int end;
uint16_t duration;
char key;
uint16_t in_digit_seq;
uint32_t ts;
if (!(packet[0] || packet[1] || packet[2] || packet[3]) && len >= 8) {
packet += 4;
len -= 4;
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_WARNING, "DTMF payload offset by 4 bytes.\n");
}
if (!(packet[0] || packet[1] || packet[2] || packet[3])) {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed DTMF payload check.\n");
rtp_session->dtmf_data.last_digit = 0;
rtp_session->dtmf_data.in_digit_ts = 0;
}
end = packet[1] & 0x80 ? 1 : 0;
duration = (packet[2] << 8) + packet[3];
key = switch_rfc2833_to_char(packet[0]);
in_digit_seq = ntohs((uint16_t) rtp_session->recv_msg.header.seq);
ts = htonl(rtp_session->recv_msg.header.ts);
if (in_digit_seq < rtp_session->dtmf_data.in_digit_seq) {
if (rtp_session->dtmf_data.in_digit_seq - in_digit_seq > 100) {
rtp_session->dtmf_data.in_digit_seq = 0;
}
}
#ifdef DEBUG_2833
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "packet[%d]: %02x %02x %02x %02x\n", (int) len, (unsigned) packet[0], (unsigned)
packet[1], (unsigned) packet[2], (unsigned) packet[3]);
#endif
if (in_digit_seq > rtp_session->dtmf_data.in_digit_seq) {
rtp_session->dtmf_data.in_digit_seq = in_digit_seq;
#ifdef DEBUG_2833
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "read: %c %u %u %u %u %d %d %s\n",
key, in_digit_seq, rtp_session->dtmf_data.in_digit_seq,
ts, duration, rtp_session->recv_msg.header.m, end, end && !rtp_session->dtmf_data.in_digit_ts ? "ignored" : "");
#endif
if (!rtp_session->dtmf_data.in_digit_queued && (rtp_session->rtp_bugs & RTP_BUG_IGNORE_DTMF_DURATION) &&
rtp_session->dtmf_data.in_digit_ts) {
switch_dtmf_t dtmf = { key, switch_core_min_dtmf_duration(0) };
#ifdef DEBUG_2833
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Early Queuing digit %c:%d\n", dtmf.digit, dtmf.duration / 8);
#endif
switch_rtp_queue_rfc2833_in(rtp_session, &dtmf);
rtp_session->dtmf_data.in_digit_queued = 1;
}
/* only set sanity if we do NOT ignore the packet */
if (rtp_session->dtmf_data.in_digit_ts) {
rtp_session->dtmf_data.in_digit_sanity = 2000;
}
if (rtp_session->dtmf_data.last_duration > duration &&
rtp_session->dtmf_data.last_duration > 0xFC17 && ts == rtp_session->dtmf_data.in_digit_ts) {
rtp_session->dtmf_data.flip++;
}
if (end) {
if (rtp_session->dtmf_data.in_digit_ts) {
switch_dtmf_t dtmf = { key, duration };
if (ts > rtp_session->dtmf_data.in_digit_ts) {
dtmf.duration += (ts - rtp_session->dtmf_data.in_digit_ts);
}
if (rtp_session->dtmf_data.flip) {
dtmf.duration += rtp_session->dtmf_data.flip * 0xFFFF;
rtp_session->dtmf_data.flip = 0;
#ifdef DEBUG_2833
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "you're welcome!\n");
#endif
}
#ifdef DEBUG_2833
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "done digit=%c ts=%u start_ts=%u dur=%u ddur=%u\n",
dtmf.digit, ts, rtp_session->dtmf_data.in_digit_ts, duration, dtmf.duration);
#endif
if (!(rtp_session->rtp_bugs & RTP_BUG_IGNORE_DTMF_DURATION) && !rtp_session->dtmf_data.in_digit_queued) {
#ifdef DEBUG_2833
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Queuing digit %c:%d\n", dtmf.digit, dtmf.duration / 8);
#endif
switch_rtp_queue_rfc2833_in(rtp_session, &dtmf);
}
rtp_session->dtmf_data.last_digit = rtp_session->dtmf_data.first_digit;
rtp_session->dtmf_data.in_digit_ts = 0;
rtp_session->dtmf_data.in_digit_sanity = 0;
rtp_session->dtmf_data.in_digit_queued = 0;
*do_cng = 1;
} else {
if (!switch_rtp_ready(rtp_session)) {
return RESULT_GOTO_END;
}
switch_cond_next();
return RESULT_GOTO_RECVFROM;
}
} else if (!rtp_session->dtmf_data.in_digit_ts) {
rtp_session->dtmf_data.in_digit_ts = ts;
rtp_session->dtmf_data.first_digit = key;
rtp_session->dtmf_data.in_digit_sanity = 2000;
}
rtp_session->dtmf_data.last_duration = duration;
} else {
#ifdef DEBUG_2833
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "drop: %c %u %u %u %u %d %d\n",
key, in_digit_seq, rtp_session->dtmf_data.in_digit_seq, ts, duration, rtp_session->recv_msg.header.m, end);
#endif
switch_cond_next();
return RESULT_GOTO_RECVFROM;
}
}
if (bytes && rtp_session->dtmf_data.in_digit_ts) {
if (!switch_rtp_ready(rtp_session)) {
return RESULT_GOTO_END;
}
if (!rtp_session->dtmf_data.in_interleaved && rtp_session->recv_msg.header.pt != rtp_session->recv_te) {
/* Drat, they are sending audio still as well as DTMF ok fine..... *sigh* */
rtp_session->dtmf_data.in_interleaved = 1;
}
if (rtp_session->dtmf_data.in_interleaved || (rtp_session->rtp_bugs & RTP_BUG_IGNORE_DTMF_DURATION)) {
if (rtp_session->recv_msg.header.pt == rtp_session->recv_te) {
return RESULT_GOTO_RECVFROM;
}
} else {
*do_cng = 1;
return RESULT_GOTO_TIMERCHECK;
}
}
return RESULT_CONTINUE;
}
static int global_init = 0;
static int rtp_common_write(switch_rtp_t *rtp_session,
rtp_msg_t *send_msg, void *data, uint32_t datalen, switch_payload_t payload, uint32_t timestamp, switch_frame_flag_t *flags);
@ -2157,6 +2335,15 @@ static void do_flush(switch_rtp_t *rtp_session)
bytes = sizeof(rtp_msg_t);
status = switch_socket_recvfrom(rtp_session->from_addr, rtp_session->sock_input, 0, (void *) &rtp_session->recv_msg, &bytes);
if (bytes) {
int do_cng = 0;
/* Make sure to handle RFC2833 packets, even if we're flushing the packets */
if (bytes > rtp_header_len && rtp_session->recv_te && rtp_session->recv_msg.header.pt == rtp_session->recv_te) {
handle_rfc2833(rtp_session, bytes, &do_cng);
#ifdef DEBUG_2833
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "*** RTP packet handled in flush loop ***\n");
#endif
}
flushed++;
@ -2196,6 +2383,51 @@ static switch_status_t read_rtp_packet(switch_rtp_t *rtp_session, switch_size_t
status = switch_socket_recvfrom(rtp_session->from_addr, rtp_session->sock_input, 0, (void *) &rtp_session->recv_msg, bytes);
ts = ntohl(rtp_session->recv_msg.header.ts);
if (*bytes ) {
uint16_t seq = ntohs((uint16_t) rtp_session->recv_msg.header.seq);
if (rtp_session->last_seq && rtp_session->last_seq+1 != seq) {
#ifdef DEBUG_MISSED_SEQ
switch_size_t flushed_packets_diff = rtp_session->stats.inbound.flush_packet_count - rtp_session->last_flush_packet_count;
switch_size_t num_missed = (switch_size_t)seq - (rtp_session->last_seq+1);
if (num_missed == 1) { /* We missed one packet */
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Missed one RTP frame with sequence [%d]%s. Time since last read [%d]\n",
rtp_session->last_seq+1, (flushed_packets_diff == 1) ? " (flushed by FS)" : " (missed)",
rtp_session->last_read_time ? switch_micro_time_now()-rtp_session->last_read_time : 0);
} else { /* We missed multiple packets */
if (flushed_packets_diff == 0) {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR,
"Missed %d RTP frames from sequence [%d] to [%d] (missed). Time since last read [%d]\n",
num_missed, rtp_session->last_seq+1, seq-1,
rtp_session->last_read_time ? switch_micro_time_now()-rtp_session->last_read_time : 0);
} else if (flushed_packets_diff == num_missed) {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR,
"Missed %d RTP frames from sequence [%d] to [%d] (flushed by FS). Time since last read [%d]\n",
num_missed, rtp_session->last_seq+1, seq-1,
rtp_session->last_read_time ? switch_micro_time_now()-rtp_session->last_read_time : 0);
} else if (num_missed > flushed_packets_diff) {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR,
"Missed %d RTP frames from sequence [%d] to [%d] (%d packets flushed by FS, %d packets missed)."
" Time since last read [%d]\n",
num_missed, rtp_session->last_seq+1, seq-1,
flushed_packets_diff, num_missed-flushed_packets_diff,
rtp_session->last_read_time ? switch_micro_time_now()-rtp_session->last_read_time : 0);
} else {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR,
"Missed %d RTP frames from sequence [%d] to [%d] (%d packets flushed by FS). Time since last read [%d]\n",
num_missed, rtp_session->last_seq+1, seq-1,
flushed_packets_diff, rtp_session->last_read_time ? switch_micro_time_now()-rtp_session->last_read_time : 0);
}
}
#endif
}
rtp_session->last_seq = seq;
}
rtp_session->last_flush_packet_count = rtp_session->stats.inbound.flush_packet_count;
rtp_session->last_read_time = switch_micro_time_now();
if (*bytes && (!rtp_session->recv_te || rtp_session->recv_msg.header.pt != rtp_session->recv_te) &&
ts && !rtp_session->jb && !rtp_session->pause_jb && ts == rtp_session->last_cng_ts) {
/* we already sent this frame..... */
@ -2836,173 +3068,20 @@ static int rtp_common_read(switch_rtp_t *rtp_session, switch_payload_t *payload_
bytes = sbytes;
}
#ifdef DEBUG_2833
if (rtp_session->dtmf_data.in_digit_sanity && !(rtp_session->dtmf_data.in_digit_sanity % 100)) {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "sanity %d\n", rtp_session->dtmf_data.in_digit_sanity);
}
#endif
if (rtp_session->dtmf_data.in_digit_sanity && !--rtp_session->dtmf_data.in_digit_sanity) {
rtp_session->dtmf_data.last_digit = 0;
rtp_session->dtmf_data.in_digit_ts = 0;
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed DTMF sanity check.\n");
}
/* RFC2833 ... like all RFC RE: VoIP, guaranteed to drive you to insanity!
We know the real rules here, but if we enforce them, it's an interop nightmare so,
we put up with as much as we can so we don't have to deal with being punished for
doing it right. Nice guys finish last!
*/
if (bytes > rtp_header_len && !switch_test_flag(rtp_session, SWITCH_RTP_FLAG_PROXY_MEDIA) &&
!switch_test_flag(rtp_session, SWITCH_RTP_FLAG_PASS_RFC2833) && rtp_session->recv_msg.header.pt == rtp_session->recv_te) {
switch_size_t len = bytes - rtp_header_len;
unsigned char *packet = (unsigned char *) rtp_session->recv_msg.body;
int end;
uint16_t duration;
char key;
uint16_t in_digit_seq;
uint32_t ts;
if (!(packet[0] || packet[1] || packet[2] || packet[3]) && len >= 8) {
packet += 4;
len -= 4;
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_WARNING, "DTMF payload offset by 4 bytes.\n");
}
if (!(packet[0] || packet[1] || packet[2] || packet[3])) {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed DTMF payload check.\n");
rtp_session->dtmf_data.last_digit = 0;
rtp_session->dtmf_data.in_digit_ts = 0;
}
end = packet[1] & 0x80 ? 1 : 0;
duration = (packet[2] << 8) + packet[3];
key = switch_rfc2833_to_char(packet[0]);
in_digit_seq = ntohs((uint16_t) rtp_session->recv_msg.header.seq);
ts = htonl(rtp_session->recv_msg.header.ts);
if (in_digit_seq < rtp_session->dtmf_data.in_digit_seq) {
if (rtp_session->dtmf_data.in_digit_seq - in_digit_seq > 100) {
rtp_session->dtmf_data.in_digit_seq = 0;
}
}
#ifdef DEBUG_2833
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "packet[%d]: %02x %02x %02x %02x\n", (int) len, (unsigned) packet[0], (unsigned)
packet[1], (unsigned) packet[2], (unsigned) packet[3]);
#endif
if (in_digit_seq > rtp_session->dtmf_data.in_digit_seq) {
rtp_session->dtmf_data.in_digit_seq = in_digit_seq;
#ifdef DEBUG_2833
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "read: %c %u %u %u %u %d %d %s\n",
key, in_digit_seq, rtp_session->dtmf_data.in_digit_seq,
ts, duration, rtp_session->recv_msg.header.m, end, end && !rtp_session->dtmf_data.in_digit_ts ? "ignored" : "");
#endif
if (!rtp_session->dtmf_data.in_digit_queued && (rtp_session->rtp_bugs & RTP_BUG_IGNORE_DTMF_DURATION) &&
rtp_session->dtmf_data.in_digit_ts) {
switch_dtmf_t dtmf = { key, switch_core_min_dtmf_duration(0) };
#ifdef DEBUG_2833
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Early Queuing digit %c:%d\n", dtmf.digit, dtmf.duration / 8);
#endif
switch_rtp_queue_rfc2833_in(rtp_session, &dtmf);
rtp_session->dtmf_data.in_digit_queued = 1;
}
/* only set sanity if we do NOT ignore the packet */
if (rtp_session->dtmf_data.in_digit_ts) {
rtp_session->dtmf_data.in_digit_sanity = 2000;
}
if (rtp_session->dtmf_data.last_duration > duration &&
rtp_session->dtmf_data.last_duration > 0xFC17 && ts == rtp_session->dtmf_data.in_digit_ts) {
rtp_session->dtmf_data.flip++;
}
if (end) {
if (rtp_session->dtmf_data.in_digit_ts) {
switch_dtmf_t dtmf = { key, duration };
if (ts > rtp_session->dtmf_data.in_digit_ts) {
dtmf.duration += (ts - rtp_session->dtmf_data.in_digit_ts);
}
if (rtp_session->dtmf_data.flip) {
dtmf.duration += rtp_session->dtmf_data.flip * 0xFFFF;
rtp_session->dtmf_data.flip = 0;
#ifdef DEBUG_2833
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "you're welcome!\n");
#endif
}
#ifdef DEBUG_2833
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "done digit=%c ts=%u start_ts=%u dur=%u ddur=%u\n",
dtmf.digit, ts, rtp_session->dtmf_data.in_digit_ts, duration, dtmf.duration);
#endif
if (!(rtp_session->rtp_bugs & RTP_BUG_IGNORE_DTMF_DURATION) && !rtp_session->dtmf_data.in_digit_queued) {
#ifdef DEBUG_2833
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Queuing digit %c:%d\n", dtmf.digit, dtmf.duration / 8);
#endif
switch_rtp_queue_rfc2833_in(rtp_session, &dtmf);
}
rtp_session->dtmf_data.last_digit = rtp_session->dtmf_data.first_digit;
rtp_session->dtmf_data.in_digit_ts = 0;
rtp_session->dtmf_data.in_digit_sanity = 0;
rtp_session->dtmf_data.in_digit_queued = 0;
do_cng = 1;
} else {
if (!switch_rtp_ready(rtp_session)) {
goto end;
}
switch_cond_next();
goto recvfrom;
}
} else if (!rtp_session->dtmf_data.in_digit_ts) {
rtp_session->dtmf_data.in_digit_ts = ts;
rtp_session->dtmf_data.first_digit = key;
rtp_session->dtmf_data.in_digit_sanity = 2000;
}
rtp_session->dtmf_data.last_duration = duration;
} else {
#ifdef DEBUG_2833
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "drop: %c %u %u %u %u %d %d\n",
key, in_digit_seq, rtp_session->dtmf_data.in_digit_seq, ts, duration, rtp_session->recv_msg.header.m, end);
#endif
switch_cond_next();
goto recvfrom;
}
}
if (rtp_session->dtmf_data.in_digit_ts) {
}
if (bytes && rtp_session->dtmf_data.in_digit_ts) {
if (!switch_rtp_ready(rtp_session)) {
goto end;
}
if (!rtp_session->dtmf_data.in_interleaved && rtp_session->recv_msg.header.pt != rtp_session->recv_te) {
/* Drat, they are sending audio still as well as DTMF ok fine..... *sigh* */
rtp_session->dtmf_data.in_interleaved = 1;
}
if (rtp_session->dtmf_data.in_interleaved || (rtp_session->rtp_bugs & RTP_BUG_IGNORE_DTMF_DURATION)) {
if (rtp_session->recv_msg.header.pt == rtp_session->recv_te) {
goto recvfrom;
}
} else {
return_cng_frame();
}
/* Handle incoming RFC2833 packets */
switch (handle_rfc2833(rtp_session, bytes, &do_cng)) {
case RESULT_GOTO_END:
goto end;
case RESULT_GOTO_RECVFROM:
goto recvfrom;
case RESULT_GOTO_TIMERCHECK:
goto timer_check;
case RESULT_CONTINUE:
goto result_continue;
}
result_continue:
timer_check:
if (do_cng) {