*/
//#define DEBUG_2833
//#define RTP_DEBUG_WRITE_DELTA
+//#define DEBUG_MISSED_SEQ
#include <switch.h>
#include <switch_stun.h>
#undef PACKAGE_NAME
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 {
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);
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++;
*bytes = sizeof(rtp_msg_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..... */
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) {