Review at  https://gerrit.osmocom.org/7773

jibuf: Add initial implementation of Jitter Buffer

Change-Id: I9688ba9c4d5b733b9f29d0f15f73750f9271ef55
---
M include/osmocom/netif/Makefile.am
A include/osmocom/netif/jibuf.h
M src/Makefile.am
A src/jibuf.c
M tests/Makefile.am
A tests/jibuf/jibuf_test.c
A tests/jibuf/jibuf_test.ok
M tests/testsuite.at
8 files changed, 1,402 insertions(+), 2 deletions(-)


  git pull ssh://gerrit.osmocom.org:29418/libosmo-netif refs/changes/73/7773/1

diff --git a/include/osmocom/netif/Makefile.am 
b/include/osmocom/netif/Makefile.am
index cbaff5c..0db78fb 100644
--- a/include/osmocom/netif/Makefile.am
+++ b/include/osmocom/netif/Makefile.am
@@ -3,6 +3,7 @@
 osmonetif_HEADERS = amr.h              \
                    channel.h           \
                    datagram.h          \
+                   jibuf.h             \
                    osmux.h             \
                    ipa.h               \
                    ipa_unit.h          \
diff --git a/include/osmocom/netif/jibuf.h b/include/osmocom/netif/jibuf.h
new file mode 100644
index 0000000..aca319a
--- /dev/null
+++ b/include/osmocom/netif/jibuf.h
@@ -0,0 +1,66 @@
+#ifndef _JIBUF_H_
+#define _JIBUF_H_
+
+#include <stdint.h>
+#include <stdbool.h>
+#include <time.h>
+
+#include <osmocom/core/timer.h>
+
+/*! \defgroup jibuf Osmocom Jitter Buffer
+ *  @{
+ */
+
+/*! \file jibuf.h
+ *  \brief Osmocom Jitter Buffer helpers
+ */
+
+typedef void (*osmo_jibuf_dequeue_cb)(struct msgb *msg, void *data);
+
+/*! \brief A structure representing a single instance of a jitter buffer */
+struct jibuf {
+       void *talloc_ctx;
+       bool started;
+       struct osmo_timer_list timer;
+       struct llist_head msg_list; /* sorted by output ts */
+       uint32_t min_delay; /* in msec */
+       uint32_t max_delay; /* in msec */
+       uint32_t threshold_delay; /* in msec */
+
+       osmo_jibuf_dequeue_cb dequeue_cb;
+       void *dequeue_cb_data;
+
+       /* number of pkt drops since we last changed the buffer size */
+       uint32_t last_dropped;
+       uint32_t consecutive_drops;
+
+       uint32_t ref_rx_ts;
+       uint32_t ref_tx_ts;
+       uint16_t ref_tx_seq;
+
+       struct timeval last_enqueue_time;
+       struct timeval next_dequeue_time;
+
+       struct {
+               uint32_t total_enqueued;
+               uint64_t total_dropped;
+       } stats;
+};
+
+
+struct jibuf *osmo_jibuf_alloc(void *talloc_ctx);
+
+void osmo_jibuf_delete(struct jibuf *jb);
+
+int osmo_jibuf_enqueue(struct jibuf *jb, struct msgb *msg);
+
+bool osmo_jibuf_empty(struct jibuf *jb);
+
+void osmo_jibuf_set_min_delay(struct jibuf *jb, uint32_t min_delay);
+void osmo_jibuf_set_max_delay(struct jibuf *jb, uint32_t max_delay);
+
+void osmo_jibuf_set_dequeue_cb(struct jibuf *jb, osmo_jibuf_dequeue_cb 
dequeue_cb, void* cb_data);
+
+/*! @} */
+
+#endif
diff --git a/src/Makefile.am b/src/Makefile.am
index 81a55b4..79e3685 100644
--- a/src/Makefile.am
+++ b/src/Makefile.am
@@ -18,6 +18,7 @@
                          datagram.c            \
                          ipa.c                 \
                          ipa_unit.c            \
+                         jibuf.c               \
                          osmux.c               \
                          rs232.c               \
                          rtp.c                 \
diff --git a/src/jibuf.c b/src/jibuf.c
new file mode 100644
index 0000000..44a86a5
--- /dev/null
+++ b/src/jibuf.c
@@ -0,0 +1,377 @@
+/* (C) 2017 by Pau Espin Pedrol <pes...@sysmocom.de>
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 2 of the License, or
+ * (at your option) any later version.
+ */
+
+#include <stdio.h>
+#include <string.h>
+#include <inttypes.h>
+
+#include <osmocom/core/msgb.h>
+#include <osmocom/core/timer.h>
+#include <osmocom/core/talloc.h>
+#include <osmocom/core/logging.h>
+#include <osmocom/core/utils.h>
+
+#include <osmocom/netif/amr.h>
+#include <osmocom/netif/rtp.h>
+#include <osmocom/netif/jibuf.h>
+
+#include <arpa/inet.h>
+
+/*! \addtogroup jibuf Osmocom Jitter Buffer
+ *  @{
+ */
+
+/*! \file jibuf.c
+ *  \brief Osmocom Jitter Buffer helpers
+ */
+
+/* Sampling rate (in Hz) */
+/* TODO: SAMPLE RATE can be guessed from rtp.p_type */
+#define SAMPLE_RATE 8000
+
+/* TUNABLE PARAMETERS: */
+
+/* default {min,max}_delay values if set_{min,max}_delay() is never called */
+#define JIBUF_DEFAULT_MIN_DELAY_MS 60
+#define JIBUF_DEFAULT_MAX_DELAY_MS 200
+
+/* How frequently (num of input packets) do we reselect a new reference? */
+#define JIBUF_REFERENCE_TS_FREQ 60
+
+/* How frequently (num of input packets) do we check if we should adapt the
+ * buffer size (threshold_delay) ? */
+#define JIBUF_BUFFER_RECALC_FREQ 40
+/* How many pkts should be dropped at max every JIBUF_BUFFER_RECALC_FREQ input
+ * pkts? */
+#define JIBUF_ALLOWED_PKT_DROP 3
+/* How many consecutive pkts can be dropped before triggering a buffer size 
incr ? */
+#define JIBUF_ALLOWED_PKT_CONSECUTIVE_DROP 1
+/* How much do we incr/decr the buffer size every time we recalculate it? */
+#define JIBUF_BUFFER_INC_STEP 20
+#define JIBUF_BUFFER_DEC_STEP 5
+
+struct jibuf_msgb_cb {
+       struct timeval ts;
+       unsigned long *old_cb;
+};
+
+#define JIBUF_MSGB_CB(__msgb) ((struct jibuf_msgb_cb *)&((__msgb)->cb[0]))
+
+static void ms2timeval(struct timeval *ts, uint32_t ms)
+{
+       ts->tv_sec = ms / 1000;
+       ts->tv_usec = (ms % 1000) * 1000;
+}
+
+static uint32_t timeval2ms(const struct timeval *ts)
+{
+       return ts->tv_sec * 1000 + ts->tv_usec / 1000;
+}
+
+static int clock_gettime_timeval(clockid_t clk_id, struct timeval *tp)
+{
+       struct timespec now;
+       int n;
+
+       n = osmo_clock_gettime(clk_id, &now);
+       tp->tv_sec = now.tv_sec;
+       tp->tv_usec = now.tv_nsec / 1000;
+
+       return n;
+}
+
+static struct timeval *msgb_scheduled_ts(const struct msgb *msg)
+{
+       struct jibuf_msgb_cb *jbcb = JIBUF_MSGB_CB(msg);
+       return &jbcb->ts;
+}
+
+/* Add msgb to the list sorted by its scheduled output ts */
+static void llist_add_sorted(struct msgb *msg, struct llist_head *msg_list)
+{
+       struct msgb *cur;
+       struct timeval *msg_ts = msgb_scheduled_ts(msg);
+
+       /* TODO: not sure if I need to use _safe here */
+       llist_for_each_entry(cur, msg_list, list) {
+               struct timeval *cur_ts = msgb_scheduled_ts(cur);
+               if (timercmp(msg_ts, cur_ts, <)) {
+                       __llist_add(&msg->list, cur->list.prev, &cur->list);
+                       return;
+               }
+       }
+
+       /* we reached the end, add to the tail: */
+       llist_add_tail(&msg->list, msg_list);
+
+}
+
+static uint16_t msg_get_sequence(struct msgb *msg)
+{
+       struct rtp_hdr *rtph = osmo_rtp_get_hdr(msg);
+       return ntohs(rtph->sequence);
+}
+
+static uint32_t msg_get_timestamp(struct msgb *msg)
+{
+       struct rtp_hdr *rtph = osmo_rtp_get_hdr(msg);
+       return ntohl(rtph->timestamp);
+}
+
+static int32_t samples2ms(int32_t samples)
+{
+       /* XXX: SAMPLE RATE can be guessed from rtp.p_type */
+       return samples * 1000 / SAMPLE_RATE;
+}
+
+/* Calculates pkt delay related to reference pkt. Similar concept to D(i,j) as
+ * defined in RFC3550 (RTP). */
+static int calc_pkt_rel_delay(struct jibuf *jb, struct msgb *msg)
+{
+       uint32_t current_rx_ts = timeval2ms(&jb->last_enqueue_time);
+       uint32_t current_tx_ts = msg_get_timestamp(msg);
+
+       return samples2ms((current_tx_ts - jb->ref_tx_ts)) - (current_rx_ts - 
jb->ref_rx_ts);
+}
+
+static void msg_set_as_reference(struct jibuf *jb, struct msgb *msg)
+{
+       jb->ref_rx_ts = timeval2ms(&jb->last_enqueue_time);
+       jb->ref_tx_ts = msg_get_timestamp(msg);
+       jb->ref_tx_seq = msg_get_sequence(msg);
+
+       LOGP(DLJIBUF, LOGL_DEBUG, "New reference (seq=%"PRIu16" rx=%"PRIu32 \
+               " tx=%"PRIu32")\n", jb->ref_tx_seq, jb->ref_rx_ts, 
jb->ref_tx_ts);
+}
+
+static void dequeue_msg(struct jibuf *jb, struct msgb *msg)
+{
+       unsigned long *old_cb = JIBUF_MSGB_CB(msg)->old_cb;
+       memcpy(msg->cb, old_cb, sizeof(msg->cb));
+       talloc_free(old_cb);
+       llist_del(&msg->list);
+
+       jb->dequeue_cb(msg, jb->dequeue_cb_data);
+}
+
+static void timer_expired(void *data)
+{
+       struct jibuf *jb = (struct jibuf*) data;
+               struct timeval delay_ts, now;
+               struct msgb *msg, *next;
+
+       llist_for_each_entry_safe(msg, next, &jb->msg_list, list) {
+       struct timeval *msg_ts = msgb_scheduled_ts(msg);
+                       clock_gettime_timeval(CLOCK_MONOTONIC, &now);
+       if (timercmp(msg_ts, &now, >)) {
+                               jb->next_dequeue_time = *msg_ts;
+                               timersub(msg_ts, &now, &delay_ts);
+                               osmo_timer_schedule(&jb->timer,
+                                       delay_ts.tv_sec, delay_ts.tv_usec);
+                               return;
+                       }
+
+                       dequeue_msg(jb, msg);
+       }
+
+       /* XXX: maybe  try to tune the threshold based on the calculated output 
jitter? */
+       /* XXX: try to find holes in the list and create fake pkts to improve 
the
+                jitter when packets do not arrive on time */
+}
+
+static void recalc_threshold_delay(struct jibuf *jb)
+{
+
+       /* Recalculate every JIBUF_RECALC_FREQ_PKTS handled packets, or if we 
have too
+                many consecutive drops */
+       uint32_t sum_pkts = jb->stats.total_enqueued + jb->stats.total_dropped +
+                                                               
jb->last_dropped;
+
+       if (jb->consecutive_drops <= JIBUF_ALLOWED_PKT_CONSECUTIVE_DROP &&
+                                       sum_pkts % JIBUF_BUFFER_RECALC_FREQ != 
0)
+               return;
+
+       if (jb->consecutive_drops > JIBUF_ALLOWED_PKT_CONSECUTIVE_DROP ||
+                                       jb->last_dropped > 
JIBUF_ALLOWED_PKT_DROP)
+               jb->threshold_delay = OSMO_MIN(
+                                       jb->threshold_delay + 
JIBUF_BUFFER_INC_STEP,
+                                       jb->max_delay);
+       else
+               jb->threshold_delay = OSMO_MAX(
+                                       jb->threshold_delay - 
JIBUF_BUFFER_DEC_STEP,
+                                       jb->min_delay);
+       LOGP(DLJIBUF, LOGL_DEBUG, "New threshold: %u ms (freq=%d dropped=%d/%d 
consecutive=%d/%d)\n",
+                       jb->threshold_delay, JIBUF_BUFFER_RECALC_FREQ,
+                       jb->last_dropped, JIBUF_ALLOWED_PKT_DROP,
+                       jb->consecutive_drops, 
JIBUF_ALLOWED_PKT_CONSECUTIVE_DROP);
+
+       jb->stats.total_dropped += jb->last_dropped;
+       jb->last_dropped = 0;
+
+}
+
+//----------------------------------
+
+/*! \brief Allocate a new jitter buffer instance
+ *  \return the new allocated instance
+ */
+struct jibuf *osmo_jibuf_alloc(void *talloc_ctx)
+{
+       struct jibuf *jb;
+       jb = talloc_zero(talloc_ctx, struct jibuf);
+
+       jb->min_delay = JIBUF_DEFAULT_MIN_DELAY_MS;
+       jb->max_delay = JIBUF_DEFAULT_MAX_DELAY_MS;
+       jb->threshold_delay = jb->min_delay;
+
+       INIT_LLIST_HEAD(&jb->msg_list);
+
+       jb->timer.cb = timer_expired;
+       jb->timer.data = jb;
+
+       return jb;
+}
+
+/*! \brief Destroy a previously allocated jitter buffer instance
+ *  \param[in] jb Previously allocated (non-null) jitter buffer instance
+ *
+ * All the queued packets are dequeued before deleting the instance.
+ */
+void osmo_jibuf_delete(struct jibuf *jb)
+{
+       struct msgb *msg, *tmp;
+       osmo_timer_del(&jb->timer);
+       llist_for_each_entry_safe(msg, tmp, &jb->msg_list, list)
+       dequeue_msg(jb, msg);
+
+       talloc_free(jb);
+}
+
+/*! \brief Try to enqueue a packet into the jitter buffer
+ *  \param[in] jb jitter buffer instance
+ *  \param[in] msg msgb to enqueue, containing an RTP packet
+ *  \return <0 if the packet was dropped, 0 otherwise
+ *
+ * This function calculates the delay for the enqueued packet. If the delay is
+ * bigger than the current buffer size, the function returns -1 and the caller
+ * owns the packet again and can free it if required. If the packet is 
enqueued,
+ * 0 is returned and the exact same packet (ownership transfer, no copy is 
made)
+ * will be available again through the dequeue_cb() when the queue timer for
+ * this packet expires.
+ */
+int osmo_jibuf_enqueue(struct jibuf *jb, struct msgb *msg)
+{
+       int rel_delay, delay;
+       struct timeval delay_ts, sched_ts;
+
+       clock_gettime_timeval(CLOCK_MONOTONIC, &jb->last_enqueue_time);
+
+       if (!jb->started) {
+               jb->started = true;
+               msg_set_as_reference(jb, msg);
+               rel_delay = 0;
+       } else {
+               rel_delay = calc_pkt_rel_delay(jb, msg);
+       }
+
+       /* Avoid time skew with sender (or drop-everything state),
+          reselect a new reference from time to time */
+       //if ((int)(msg_get_sequence(msg) - jb->ref_tx_seq) > 
JIBUF_REFERENCE_TS_FREQ)
+       //      msg_set_as_reference(jb, msg);
+
+       delay = jb->threshold_delay + rel_delay;
+
+       /* packet too late, let's drop it and incr buffer size if encouraged */
+       if (delay < 0) {
+               jb->last_dropped++;
+               jb->consecutive_drops++;
+
+               LOGP(DLJIBUF, LOGL_DEBUG, "dropped %u > %u (seq=%"PRIu16" 
ts=%"PRIu32")\n",
+                       rel_delay, jb->threshold_delay, msg_get_sequence(msg),
+                       msg_get_timestamp(msg));
+
+               recalc_threshold_delay(jb);
+               return -1;
+       } else {
+               jb->consecutive_drops = 0;
+               jb->stats.total_enqueued++;
+       }
+
+       ms2timeval(&delay_ts, (uint32_t) delay);
+       timeradd(&jb->last_enqueue_time, &delay_ts, &sched_ts);
+
+       LOGP(DLJIBUF, LOGL_DEBUG, "enqueuing packet seq=%"PRIu16" rel=%d 
delay=%d" \
+               " thres=%d {%lu.%06lu -> %lu.%06lu}\n",
+               msg_get_sequence(msg), rel_delay, delay, jb->threshold_delay,
+               jb->last_enqueue_time.tv_sec, jb->last_enqueue_time.tv_usec,
+               sched_ts.tv_sec, sched_ts.tv_usec);
+
+       /* Add scheduled dequeue time in msg->cb so we can check it later */
+       unsigned long *old_cb = talloc_memdup(jb->talloc_ctx, msg->cb, 
sizeof(msg->cb));
+       struct jibuf_msgb_cb *jbcb = JIBUF_MSGB_CB(msg);
+       jbcb->ts = sched_ts;
+       jbcb->old_cb = old_cb;
+
+       llist_add_sorted(msg, &jb->msg_list);
+
+
+       /* See if updating the timer is needed: */
+       if (!osmo_timer_pending(&jb->timer) ||
+                       timercmp(&sched_ts, &jb->next_dequeue_time, <))  {
+               jb->next_dequeue_time = sched_ts;
+               osmo_timer_schedule(&jb->timer, 0, delay * 1000);
+       }
+
+       /* Let's check packet loss stats to see if buffer_size must be changed 
*/
+       recalc_threshold_delay(jb);
+
+       return 0;
+}
+
+/*! \brief Check whether the jitter buffer instance has packets queued or not.
+ *  \param[in] jb jitter buffer instance
+ *  \return true if the queue is empty, false otherwise.
+ */
+bool osmo_jibuf_empty(struct jibuf *jb)
+{
+       return llist_empty(&jb->msg_list);
+}
+
+/*! \brief Set minimum buffer size for the jitter buffer
+ *  \param[in] jb jitter buffer instance
+ *  \param[in] min_delay Minimum buffer size, as in minimum delay in 
milliseconds
+ */
+void osmo_jibuf_set_min_delay(struct jibuf *jb, uint32_t min_delay)
+{
+       jb->min_delay = min_delay ? min_delay : JIBUF_DEFAULT_MIN_DELAY_MS;
+       jb->threshold_delay = OSMO_MAX(jb->min_delay, jb->threshold_delay);
+}
+
+/*! \brief Set maximum buffer size for the jitter buffer
+ *  \param[in] jb jitter buffer instance
+ *  \param[in] max_delay Maximum buffer size, as in maximum delay in 
milliseconds
+ */
+void osmo_jibuf_set_max_delay(struct jibuf *jb, uint32_t max_delay)
+{
+       jb->max_delay = max_delay ? max_delay : JIBUF_DEFAULT_MAX_DELAY_MS;
+       jb->threshold_delay = OSMO_MIN(jb->max_delay, jb->threshold_delay);
+}
+
+/*! \brief Set dequeue callback for the jitter buffer
+ *  \param[in] jb jitter buffer instance
+ *  \param[in] dequeue_cb function pointer to call back when the dequeue timer 
for a given packet expires
+ *  \param[in] cb_data data pointer to be passed to dequeue_cb together with 
the msgb.
+ */
+void osmo_jibuf_set_dequeue_cb(struct jibuf *jb, osmo_jibuf_dequeue_cb
+                                               dequeue_cb, void* cb_data)
+{
+       jb->dequeue_cb = dequeue_cb;
+       jb->dequeue_cb_data = cb_data;
+}
+
+/*! @} */
diff --git a/tests/Makefile.am b/tests/Makefile.am
index f99e276..bf1db1f 100644
--- a/tests/Makefile.am
+++ b/tests/Makefile.am
@@ -1,10 +1,13 @@
 AM_CFLAGS = -Wall -I$(top_srcdir)/include $(LIBOSMOCORE_CFLAGS) -g
 AM_LDFLAGS = $(LIBOSMOCORE_LDFLAGS)
 
-check_PROGRAMS = osmux/osmux_test
+check_PROGRAMS = osmux/osmux_test jibuf/jibuf_test
 
 osmux_osmux_test_SOURCES = osmux/osmux_test.c
 osmux_osmux_test_LDADD = $(LIBOSMOCORE_LIBS) 
$(top_builddir)/src/libosmonetif.la
+
+jibuf_jibuf_test_SOURCES = jibuf/jibuf_test.c
+jibuf_jibuf_test_LDADD = $(LIBOSMOCORE_LIBS) 
$(top_builddir)/src/libosmonetif.la
 
 # The `:;' works around a Bash 3.2 bug when the output is not writeable.
 $(srcdir)/package.m4: $(top_srcdir)/configure.ac
@@ -25,7 +28,8 @@
             } >'$(srcdir)/package.m4'
 
 EXTRA_DIST = testsuite.at $(srcdir)/package.m4 $(TESTSUITE)            \
-            osmux/osmux_test.ok
+            osmux/osmux_test.ok \
+            jibuf/jibuf_test.ok
 
 DISTCLEANFILES = atconfig
 
diff --git a/tests/jibuf/jibuf_test.c b/tests/jibuf/jibuf_test.c
new file mode 100644
index 0000000..69a6d2f
--- /dev/null
+++ b/tests/jibuf/jibuf_test.c
@@ -0,0 +1,594 @@
+/* (C) 207 by Pau Espin Pedrol <pes...@sysmocom.de>
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 2 of the License, or
+ * (at your option) any later version.
+ */
+
+#include <stdio.h>
+#include <stdlib.h>
+#include <stdbool.h>
+#include <unistd.h>
+#include <stdint.h>
+#include <inttypes.h>
+#include <string.h>
+#include <signal.h>
+#include <arpa/inet.h>
+#include <sys/time.h>
+#include <getopt.h>
+
+#include <osmocom/core/select.h>
+#include <osmocom/core/application.h>
+#include <osmocom/core/logging.h>
+#include <osmocom/core/msgb.h>
+#include <osmocom/netif/jibuf.h>
+#include <osmocom/netif/rtp.h>
+
+static struct jibuf *jb;
+
+static uint16_t rtp_next_seq;
+static uint32_t rtp_next_ts;
+
+#define SAMPLES_PER_PKT        160
+#define TIME_RTP_PKT_MS 20
+/* RTP packet with AMR payload */
+static uint8_t rtp_pkt[] = {
+       0x80, 0x62, 0x3f, 0xcc, 0x00, 0x01, 0xa7, 0x6f, /* RTP */
+       0x07, 0x09, 0x00, 0x62, 0x20, 0x14, 0xff, 0xd4, /* AMR */
+       0xf9, 0xff, 0xfb, 0xe7, 0xeb, 0xf9, 0x9f, 0xf8,
+       0xf2, 0x26, 0x33, 0x65, 0x54,
+};
+
+/* ----------------------------- */
+
+/* Logging related stuff */
+#define INT2IDX(x)   (-1*(x)-1)
+struct log_info_cat jibuf_test_cat[] = {
+       [INT2IDX(DLJIBUF)] = {
+               .name = "DLJIBUF",
+               .description = "Osmocom Jitter Buffer",
+               .enabled = 1, .loglevel = LOGL_DEBUG,
+               },
+};
+const struct log_info jibuf_test_log_info = {
+       .filter_fn = NULL,
+       .cat = jibuf_test_cat,
+       .num_cat = ARRAY_SIZE(jibuf_test_cat),
+};
+/* ----------------------------- */
+
+static void rtp_init(uint16_t seq, uint32_t timestamp)
+{
+       rtp_next_seq = seq;
+       rtp_next_ts = timestamp;
+}
+
+static struct msgb *rtp_new(uint16_t seq, uint32_t timestamp)
+{
+       struct msgb *msg;
+       struct rtp_hdr *rtph;
+
+       msg = msgb_alloc(1500, "test");
+       if (!msg)
+               exit(EXIT_FAILURE);
+       memcpy(msg->data, rtp_pkt, sizeof(rtp_pkt));
+       msgb_put(msg, sizeof(rtp_pkt));
+
+       rtph = osmo_rtp_get_hdr(msg);
+       rtph->sequence = htons(rtp_next_seq);
+       rtph->timestamp = htonl(rtp_next_ts);
+       return msg;
+}
+
+static struct msgb *rtp_next(void)
+{
+       rtp_next_seq++;
+       rtp_next_ts += SAMPLES_PER_PKT;
+       return rtp_new(rtp_next_seq, rtp_next_ts);
+}
+
+static void sigalarm_handler(int foo)
+{
+       printf("FAIL: test did not run successfully\n");
+       exit(EXIT_FAILURE);
+}
+
+
+static void clock_debug(char* str)
+{
+       struct timespec ts;
+       struct timeval tv;
+       osmo_clock_gettime(CLOCK_MONOTONIC, &ts);
+       osmo_gettimeofday(&tv, NULL);
+       printf("sys={%lu.%06lu}, mono={%lu.%06lu}: %s\n",
+               tv.tv_sec, tv.tv_usec, ts.tv_sec, ts.tv_nsec/1000, str);
+}
+
+static void clock_override_enable(bool enable)
+{
+       osmo_gettimeofday_override = enable;
+       osmo_clock_override_enable(CLOCK_MONOTONIC, enable);
+}
+
+static void clock_override_set(long sec, long usec)
+{
+       struct timespec *mono;
+       osmo_gettimeofday_override_time.tv_sec = sec;
+       osmo_gettimeofday_override_time.tv_usec = usec;
+       mono = osmo_clock_override_gettimespec(CLOCK_MONOTONIC);
+       mono->tv_sec = sec;
+       mono->tv_nsec = usec*1000;
+
+       clock_debug("clock_override_set");
+}
+
+static void clock_override_add(long sec, long usec)
+{
+       osmo_gettimeofday_override_add(sec, usec);
+       osmo_clock_override_add(CLOCK_MONOTONIC, sec, usec*1000);
+       clock_debug("clock_override_add");
+}
+
+
+static void dequeue_cb(struct msgb *msg, void *data)
+{
+       struct rtp_hdr *rtph;
+       bool check_latest;
+       char buf[250];
+       rtph = osmo_rtp_get_hdr(msg);
+       check_latest = rtph->sequence == htons(rtp_next_seq) && rtph->timestamp 
== htonl(rtp_next_ts);
+       snprintf(buf, sizeof(buf), "dequeue: seq=%"PRIu16" ts=%"PRIu32" %s",
+               ntohs(rtph->sequence), ntohl(rtph->timestamp), check_latest ? 
"LATEST" : "INTERMEDIATE");
+       clock_debug(buf);
+       msgb_free(msg);
+}
+
+#define ENQUEUE_NEXT(jb) { \
+               struct msgb *_msg; \
+               int _rc; \
+               _msg = rtp_next(); \
+               _rc = osmo_jibuf_enqueue(jb, _msg); \
+               OSMO_ASSERT(!_rc); \
+               }
+
+static void test_normal(void)
+{
+       int min_delay = 60;
+
+       printf("===test_normal===\n");
+
+       clock_override_enable(true);
+       clock_override_set(0, 0);
+       rtp_init(32, 400);
+       jb = osmo_jibuf_alloc(NULL);
+       osmo_jibuf_set_dequeue_cb(jb, dequeue_cb, NULL);
+       osmo_jibuf_set_min_delay(jb, min_delay);
+       osmo_jibuf_set_max_delay(jb, 200);
+
+       /* First rtp at t=0, should be scheduled in min_delay time */
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, min_delay*1000);
+       clock_debug("first select, first dequed");
+       osmo_select_main(0);
+
+        /* We are at t=60, if we add a new packet and wait for 20msecs (next 
packet), we should show it dequeued*/
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("second select, one packet should be dequeued");
+       osmo_select_main(0);
+
+       /* We are at t=80, and only 2 packets were introduced. Let's add 2 
more, should be dequeued by 80+40: */
+       ENQUEUE_NEXT(jb);
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*2*1000);
+       clock_debug("third select, two more dequed");
+       osmo_select_main(0);
+
+       /* t=120, 4 enqueued, 4 dequeued.*/
+       OSMO_ASSERT(osmo_jibuf_empty(jb));
+
+       osmo_jibuf_delete(jb);
+}
+
+static void test_delete_nonempty(void)
+{
+       int min_delay = 100;
+
+       printf("===test_delete_nonempty===\n");
+
+       clock_override_enable(true);
+       clock_override_set(0, 0);
+       rtp_init(32, 400);
+       jb = osmo_jibuf_alloc(NULL);
+       osmo_jibuf_set_dequeue_cb(jb, dequeue_cb, NULL);
+       osmo_jibuf_set_min_delay(jb, min_delay);
+       osmo_jibuf_set_max_delay(jb, 200);
+
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       ENQUEUE_NEXT(jb);
+
+       /* No need to update the time, all msgs should be dequeued at this time 
*/
+       OSMO_ASSERT(!osmo_jibuf_empty(jb));
+       osmo_jibuf_delete(jb);
+}
+
+static void test_packet_lost(void)
+{
+       int min_delay = 60;
+
+       printf("===test_packet_lost===\n");
+
+       clock_override_enable(true);
+       clock_override_set(0, 0);
+       rtp_init(32, 400);
+       jb = osmo_jibuf_alloc(NULL);
+       osmo_jibuf_set_dequeue_cb(jb, dequeue_cb, NULL);
+       osmo_jibuf_set_min_delay(jb, min_delay);
+       osmo_jibuf_set_max_delay(jb, 200);
+
+       /* First rtp at t=0, should be scheduled in min_delay time */
+       clock_debug("enqueue 1st packet");
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+
+       clock_debug("packet lost: 2nd");
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("packet lost: 3rd");
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("packet lost: 4th");
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+
+       /* We are at t=80 */
+       clock_debug("enqueue 5th packet");
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, min_delay*1000);
+
+       /* We are at t=140, all out in order */
+       osmo_select_main(0);
+
+       OSMO_ASSERT(osmo_jibuf_empty(jb));
+
+       osmo_jibuf_delete(jb);
+}
+
+
+static void test_packet_drop(void)
+{
+       int min_delay = 60;
+       struct msgb *msg;
+
+       printf("===test_packet_drop===\n");
+
+       clock_override_enable(true);
+       clock_override_set(0, 0);
+       rtp_init(32, 400);
+       jb = osmo_jibuf_alloc(NULL);
+       osmo_jibuf_set_dequeue_cb(jb, dequeue_cb, NULL);
+       osmo_jibuf_set_min_delay(jb, min_delay);
+       osmo_jibuf_set_max_delay(jb, 200);
+
+       /* First rtp at t=0, should be scheduled in min_delay time */
+       clock_debug("enqueue 1st packet");
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("enqueue 2nd packet");
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("enqueue 3rd packet");
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("enqueue 4th packet");
+       ENQUEUE_NEXT(jb);
+
+       /* We are at t=60, first comes out */
+       osmo_select_main(0);
+
+       /* We move to t=160, next packet in stream is too late:*/
+       clock_override_add(0, 100*1000);
+       clock_debug("next packet should be dropped, too late");
+       msg = rtp_next();
+       OSMO_ASSERT(osmo_jibuf_enqueue(jb, msg) < 0);
+       msgb_free(msg);
+
+       /* However, if we try to add a later one, it should work: */
+       clock_debug("next packet should be enqueued");
+       ENQUEUE_NEXT(jb);
+
+       /* We are at t=160, all of them should be dequeued */
+       osmo_select_main(0);
+
+       /* t=160, 4 enqueued, 4 dequeued.*/
+       OSMO_ASSERT(osmo_jibuf_empty(jb));
+
+       osmo_jibuf_delete(jb);
+}
+
+static void test_packet_out_of_order(void)
+{
+       int min_delay = 60;
+       struct msgb *msg2, *msg3;
+
+       printf("===test_packet_out_of_order===\n");
+
+       clock_override_enable(true);
+       clock_override_set(0, 0);
+       rtp_init(32, 400);
+       jb = osmo_jibuf_alloc(NULL);
+       osmo_jibuf_set_dequeue_cb(jb, dequeue_cb, NULL);
+       osmo_jibuf_set_min_delay(jb, min_delay);
+       osmo_jibuf_set_max_delay(jb, 200);
+
+       /* First rtp at t=0, should be scheduled in min_delay time */
+       clock_debug("enqueue 1st packet");
+       ENQUEUE_NEXT(jb);
+
+       /* 3rd packet arrives instead of 2nd one */
+       msg2 = rtp_next();
+       msg3 = rtp_next();
+       clock_override_add(0, TIME_RTP_PKT_MS*2*1000);
+       clock_debug("enqueue 3rd packet");
+       OSMO_ASSERT(osmo_jibuf_enqueue(jb, msg3) == 0);
+       clock_debug("enqueue 2nd packet");
+       OSMO_ASSERT(osmo_jibuf_enqueue(jb, msg2) == 0);
+
+       /* We are at t=100, all out in order */
+       clock_override_add(0, min_delay*1000);
+       osmo_select_main(0);
+
+       OSMO_ASSERT(osmo_jibuf_empty(jb));
+
+       osmo_jibuf_delete(jb);
+}
+
+static void test_start_2nd_packet(void)
+{
+       int min_delay = 60;
+       struct msgb *msg1;
+
+       printf("===test_start_2nd_packet===\n");
+
+       clock_override_enable(true);
+       clock_override_set(0, 0);
+       rtp_init(32, 400);
+       jb = osmo_jibuf_alloc(NULL);
+       osmo_jibuf_set_dequeue_cb(jb, dequeue_cb, NULL);
+       osmo_jibuf_set_min_delay(jb, min_delay);
+       osmo_jibuf_set_max_delay(jb, 200);
+
+       /* First rtp at t=0, should be scheduled in min_delay time */
+       clock_debug("1st packet is not yet enqueued");
+       msg1 = rtp_next();
+       clock_override_add(0, TIME_RTP_PKT_MS*2*1000);
+
+       /* 2nd packet arrives instead of 2nd one */
+       clock_debug("2nd packet is enqueuded as first");
+       ENQUEUE_NEXT(jb);
+
+       clock_debug("1st packet is enqueuded as second, should be enqueued with 
preference");
+       OSMO_ASSERT(osmo_jibuf_enqueue(jb, msg1) == 0);
+
+       /* 1st packet is dequeued */
+       clock_override_add(0, (min_delay-TIME_RTP_PKT_MS)*1000);
+       osmo_select_main(0);
+
+       /* 2nst packet is dequeued */
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       osmo_select_main(0);
+
+       OSMO_ASSERT(osmo_jibuf_empty(jb));
+
+       osmo_jibuf_delete(jb);
+}
+
+static void test_buffer_threshold_change(void)
+{
+       int min_delay = 60;
+       struct msgb *msg;
+       uint32_t threshold_delay;
+       int i;
+
+       printf("===test_buffer_threshold_change===\n");
+
+       clock_override_enable(true);
+       clock_override_set(0, 0);
+       rtp_init(32, 400);
+       jb = osmo_jibuf_alloc(NULL);
+       osmo_jibuf_set_dequeue_cb(jb, dequeue_cb, NULL);
+       osmo_jibuf_set_min_delay(jb, min_delay);
+       osmo_jibuf_set_max_delay(jb, 200);
+
+       OSMO_ASSERT(min_delay == jb->threshold_delay);
+       threshold_delay = jb->threshold_delay;
+
+       /* First rtp at t=0, should be scheduled in min_delay time */
+       clock_debug("enqueue 1st packet");
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("enqueue 2nd packet");
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("enqueue 3rd packet");
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("enqueue 4th packet");
+       ENQUEUE_NEXT(jb);
+
+       /* We are at t=60, first comes out */
+       osmo_select_main(0);
+
+       /* We move to t=160, next packet in stream is too late:*/
+       clock_override_add(0, 100*1000);
+       clock_debug("next packet should be dropped, too late");
+       msg = rtp_next();
+       OSMO_ASSERT(osmo_jibuf_enqueue(jb, msg) < 0);
+       msgb_free(msg);
+
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("next packet is dropped, but buffer is increased");
+       msg = rtp_next();
+       OSMO_ASSERT(osmo_jibuf_enqueue(jb, msg) < 0);
+       msgb_free(msg);
+       OSMO_ASSERT(jb->threshold_delay > threshold_delay);
+       threshold_delay = jb->threshold_delay;
+
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("next packet is enqueued since the buffer increased");
+       ENQUEUE_NEXT(jb);
+
+       /* As the last buffer was really late but still accepted, it is not 
delayed: */
+       osmo_select_main(0);
+
+       clock_debug("Enqueue late packets");
+       for (i = 0; i<4; i++) {
+               ENQUEUE_NEXT(jb);
+       }
+
+       clock_debug("Run perfectly for a while, buffer should decrease");
+       for (i = 0; i<100; i++) {
+               clock_override_add(0, TIME_RTP_PKT_MS*1000);
+               ENQUEUE_NEXT(jb);
+               osmo_select_main(0);
+       }
+       clock_debug("Done, checking threshold and cleaning");
+       OSMO_ASSERT(jb->threshold_delay < threshold_delay);
+       clock_override_add(0, jb->threshold_delay*1000);
+       osmo_select_main(0);
+
+       OSMO_ASSERT(osmo_jibuf_empty(jb));
+
+       osmo_jibuf_delete(jb);
+}
+
+static void test_seq_wraparound(void)
+{
+       int min_delay = 80;
+
+       printf("===test_seq_wraparound===\n");
+
+       clock_override_enable(true);
+       clock_override_set(0, 0);
+       rtp_init(65533, 400); /* seq = 2^16 -3 */
+       jb = osmo_jibuf_alloc(NULL);
+       osmo_jibuf_set_dequeue_cb(jb, dequeue_cb, NULL);
+       osmo_jibuf_set_min_delay(jb, min_delay);
+       osmo_jibuf_set_max_delay(jb, 200);
+
+       clock_debug("enqueue 1st packet (seq=65534)");
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("enqueue 2nd packet (seq=65535)");
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("enqueue 3rd packet (seq=0, wraparound)");
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("enqueue 4th packet (seq=1)");
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("enqueue 5th packet (seq=2)");
+       ENQUEUE_NEXT(jb);
+
+       clock_debug("dequeue 1st packet (seq=65534)");
+       osmo_select_main(0);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("dequeue 2nd packet (seq=65535)");
+       osmo_select_main(0);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("dequeue 3rd packet (seq=0, wraparound)");
+       osmo_select_main(0);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("dequeue 4th packet (seq=1)");
+       osmo_select_main(0);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("dequeue 5th packet (seq=2)");
+       osmo_select_main(0);
+
+       OSMO_ASSERT(osmo_jibuf_empty(jb));
+
+       osmo_jibuf_delete(jb);
+}
+
+static void test_timestamp_wraparound(void)
+{
+       int min_delay = 80;
+       unsigned int offset = 14;
+
+       printf("===test_timestamp_wraparound===\n");
+
+       clock_override_enable(true);
+       clock_override_set(0, 0);
+       rtp_init(32, 4294966816 + offset); /* timestamp = 2^32 - 
3*SAMPLES_PER_PKT + offset */
+       jb = osmo_jibuf_alloc(NULL);
+       osmo_jibuf_set_dequeue_cb(jb, dequeue_cb, NULL);
+       osmo_jibuf_set_min_delay(jb, min_delay);
+       osmo_jibuf_set_max_delay(jb, 200);
+
+       clock_debug("enqueue 1st packet (ts=4294966990)");
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("enqueue 2nd packet (ts=4294967150)");
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("enqueue 3rd packet (ts=14, wraparound)");
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("enqueue 4th packet (ts=174)");
+       ENQUEUE_NEXT(jb);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("enqueue 5th packet (ts=334)");
+       ENQUEUE_NEXT(jb);
+
+       clock_debug("dequeue 1st packet (ts=4294966990)");
+       osmo_select_main(0);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("dequeue 2nd packet (ts=4294967150)");
+       osmo_select_main(0);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("dequeue 3rd packet (ts=14, wraparound)");
+       osmo_select_main(0);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("dequeue 4th packet (ts=174)");
+       osmo_select_main(0);
+       clock_override_add(0, TIME_RTP_PKT_MS*1000);
+       clock_debug("dequeue 5th packet (ts=334)");
+       osmo_select_main(0);
+
+       OSMO_ASSERT(osmo_jibuf_empty(jb));
+
+       osmo_jibuf_delete(jb);
+}
+
+int main(int argc, char **argv)
+{
+
+       if (signal(SIGALRM, sigalarm_handler) == SIG_ERR) {
+               perror("signal");
+               exit(EXIT_FAILURE);
+       }
+
+       osmo_init_logging(&jibuf_test_log_info);
+       log_set_print_filename(osmo_stderr_target, 0);
+       log_set_log_level(osmo_stderr_target, LOGL_DEBUG);
+       log_set_category_filter(osmo_stderr_target, DLJIBUF, 1, LOGL_DEBUG);
+
+       alarm(10);
+
+       test_normal();
+       test_delete_nonempty();
+       test_packet_lost();
+       test_packet_drop();
+       test_packet_out_of_order();
+       test_start_2nd_packet();
+       test_buffer_threshold_change();
+       test_seq_wraparound();
+       test_timestamp_wraparound();
+
+       fprintf(stdout, "OK: Test passed\n");
+       return EXIT_SUCCESS;
+}
diff --git a/tests/jibuf/jibuf_test.ok b/tests/jibuf/jibuf_test.ok
new file mode 100644
index 0000000..5a0f121
--- /dev/null
+++ b/tests/jibuf/jibuf_test.ok
@@ -0,0 +1,351 @@
+===test_normal===
+sys={0.000000}, mono={0.000000}: clock_override_set
+sys={0.060000}, mono={0.060000}: clock_override_add
+sys={0.060000}, mono={0.060000}: first select, first dequed
+sys={0.060000}, mono={0.060000}: dequeue: seq=33 ts=560 LATEST
+sys={0.080000}, mono={0.080000}: clock_override_add
+sys={0.080000}, mono={0.080000}: second select, one packet should be dequeued
+sys={0.080000}, mono={0.080000}: dequeue: seq=34 ts=720 LATEST
+sys={0.120000}, mono={0.120000}: clock_override_add
+sys={0.120000}, mono={0.120000}: third select, two more dequed
+sys={0.120000}, mono={0.120000}: dequeue: seq=35 ts=880 INTERMEDIATE
+sys={0.120000}, mono={0.120000}: dequeue: seq=36 ts=1040 LATEST
+===test_delete_nonempty===
+sys={0.000000}, mono={0.000000}: clock_override_set
+sys={0.020000}, mono={0.020000}: clock_override_add
+sys={0.040000}, mono={0.040000}: clock_override_add
+sys={0.060000}, mono={0.060000}: clock_override_add
+sys={0.060000}, mono={0.060000}: dequeue: seq=33 ts=560 INTERMEDIATE
+sys={0.060000}, mono={0.060000}: dequeue: seq=34 ts=720 INTERMEDIATE
+sys={0.060000}, mono={0.060000}: dequeue: seq=35 ts=880 INTERMEDIATE
+sys={0.060000}, mono={0.060000}: dequeue: seq=36 ts=1040 LATEST
+===test_packet_lost===
+sys={0.000000}, mono={0.000000}: clock_override_set
+sys={0.000000}, mono={0.000000}: enqueue 1st packet
+sys={0.020000}, mono={0.020000}: clock_override_add
+sys={0.020000}, mono={0.020000}: packet lost: 2nd
+sys={0.040000}, mono={0.040000}: clock_override_add
+sys={0.040000}, mono={0.040000}: packet lost: 3rd
+sys={0.060000}, mono={0.060000}: clock_override_add
+sys={0.060000}, mono={0.060000}: packet lost: 4th
+sys={0.080000}, mono={0.080000}: clock_override_add
+sys={0.080000}, mono={0.080000}: enqueue 5th packet
+sys={0.140000}, mono={0.140000}: clock_override_add
+sys={0.140000}, mono={0.140000}: dequeue: seq=33 ts=560 INTERMEDIATE
+sys={0.140000}, mono={0.140000}: dequeue: seq=34 ts=720 LATEST
+===test_packet_drop===
+sys={0.000000}, mono={0.000000}: clock_override_set
+sys={0.000000}, mono={0.000000}: enqueue 1st packet
+sys={0.020000}, mono={0.020000}: clock_override_add
+sys={0.020000}, mono={0.020000}: enqueue 2nd packet
+sys={0.040000}, mono={0.040000}: clock_override_add
+sys={0.040000}, mono={0.040000}: enqueue 3rd packet
+sys={0.060000}, mono={0.060000}: clock_override_add
+sys={0.060000}, mono={0.060000}: enqueue 4th packet
+sys={0.060000}, mono={0.060000}: dequeue: seq=33 ts=560 INTERMEDIATE
+sys={0.160000}, mono={0.160000}: clock_override_add
+sys={0.160000}, mono={0.160000}: next packet should be dropped, too late
+sys={0.160000}, mono={0.160000}: next packet should be enqueued
+sys={0.160000}, mono={0.160000}: dequeue: seq=34 ts=720 INTERMEDIATE
+sys={0.160000}, mono={0.160000}: dequeue: seq=35 ts=880 INTERMEDIATE
+sys={0.160000}, mono={0.160000}: dequeue: seq=36 ts=1040 INTERMEDIATE
+sys={0.160000}, mono={0.160000}: dequeue: seq=38 ts=1360 LATEST
+===test_packet_out_of_order===
+sys={0.000000}, mono={0.000000}: clock_override_set
+sys={0.000000}, mono={0.000000}: enqueue 1st packet
+sys={0.040000}, mono={0.040000}: clock_override_add
+sys={0.040000}, mono={0.040000}: enqueue 3rd packet
+sys={0.040000}, mono={0.040000}: enqueue 2nd packet
+sys={0.100000}, mono={0.100000}: clock_override_add
+sys={0.100000}, mono={0.100000}: dequeue: seq=33 ts=560 INTERMEDIATE
+sys={0.100000}, mono={0.100000}: dequeue: seq=34 ts=720 INTERMEDIATE
+sys={0.100000}, mono={0.100000}: dequeue: seq=35 ts=880 LATEST
+===test_start_2nd_packet===
+sys={0.000000}, mono={0.000000}: clock_override_set
+sys={0.000000}, mono={0.000000}: 1st packet is not yet enqueued
+sys={0.040000}, mono={0.040000}: clock_override_add
+sys={0.040000}, mono={0.040000}: 2nd packet is enqueuded as first
+sys={0.040000}, mono={0.040000}: 1st packet is enqueuded as second, should be 
enqueued with preference
+sys={0.080000}, mono={0.080000}: clock_override_add
+sys={0.080000}, mono={0.080000}: dequeue: seq=33 ts=560 INTERMEDIATE
+sys={0.100000}, mono={0.100000}: clock_override_add
+sys={0.100000}, mono={0.100000}: dequeue: seq=34 ts=720 LATEST
+===test_buffer_threshold_change===
+sys={0.000000}, mono={0.000000}: clock_override_set
+sys={0.000000}, mono={0.000000}: enqueue 1st packet
+sys={0.020000}, mono={0.020000}: clock_override_add
+sys={0.020000}, mono={0.020000}: enqueue 2nd packet
+sys={0.040000}, mono={0.040000}: clock_override_add
+sys={0.040000}, mono={0.040000}: enqueue 3rd packet
+sys={0.060000}, mono={0.060000}: clock_override_add
+sys={0.060000}, mono={0.060000}: enqueue 4th packet
+sys={0.060000}, mono={0.060000}: dequeue: seq=33 ts=560 INTERMEDIATE
+sys={0.160000}, mono={0.160000}: clock_override_add
+sys={0.160000}, mono={0.160000}: next packet should be dropped, too late
+sys={0.180000}, mono={0.180000}: clock_override_add
+sys={0.180000}, mono={0.180000}: next packet is dropped, but buffer is 
increased
+sys={0.200000}, mono={0.200000}: clock_override_add
+sys={0.200000}, mono={0.200000}: next packet is enqueued since the buffer 
increased
+sys={0.200000}, mono={0.200000}: dequeue: seq=34 ts=720 INTERMEDIATE
+sys={0.200000}, mono={0.200000}: dequeue: seq=35 ts=880 INTERMEDIATE
+sys={0.200000}, mono={0.200000}: dequeue: seq=36 ts=1040 INTERMEDIATE
+sys={0.200000}, mono={0.200000}: dequeue: seq=39 ts=1520 LATEST
+sys={0.200000}, mono={0.200000}: Enqueue late packets
+sys={0.200000}, mono={0.200000}: Run perfectly for a while, buffer should 
decrease
+sys={0.220000}, mono={0.220000}: clock_override_add
+sys={0.220000}, mono={0.220000}: dequeue: seq=40 ts=1680 INTERMEDIATE
+sys={0.240000}, mono={0.240000}: clock_override_add
+sys={0.240000}, mono={0.240000}: dequeue: seq=41 ts=1840 INTERMEDIATE
+sys={0.260000}, mono={0.260000}: clock_override_add
+sys={0.260000}, mono={0.260000}: dequeue: seq=42 ts=2000 INTERMEDIATE
+sys={0.280000}, mono={0.280000}: clock_override_add
+sys={0.280000}, mono={0.280000}: dequeue: seq=43 ts=2160 INTERMEDIATE
+sys={0.300000}, mono={0.300000}: clock_override_add
+sys={0.300000}, mono={0.300000}: dequeue: seq=44 ts=2320 INTERMEDIATE
+sys={0.320000}, mono={0.320000}: clock_override_add
+sys={0.320000}, mono={0.320000}: dequeue: seq=45 ts=2480 INTERMEDIATE
+sys={0.340000}, mono={0.340000}: clock_override_add
+sys={0.340000}, mono={0.340000}: dequeue: seq=46 ts=2640 INTERMEDIATE
+sys={0.360000}, mono={0.360000}: clock_override_add
+sys={0.360000}, mono={0.360000}: dequeue: seq=47 ts=2800 INTERMEDIATE
+sys={0.380000}, mono={0.380000}: clock_override_add
+sys={0.380000}, mono={0.380000}: dequeue: seq=48 ts=2960 INTERMEDIATE
+sys={0.400000}, mono={0.400000}: clock_override_add
+sys={0.400000}, mono={0.400000}: dequeue: seq=49 ts=3120 INTERMEDIATE
+sys={0.420000}, mono={0.420000}: clock_override_add
+sys={0.420000}, mono={0.420000}: dequeue: seq=50 ts=3280 INTERMEDIATE
+sys={0.440000}, mono={0.440000}: clock_override_add
+sys={0.440000}, mono={0.440000}: dequeue: seq=51 ts=3440 INTERMEDIATE
+sys={0.460000}, mono={0.460000}: clock_override_add
+sys={0.460000}, mono={0.460000}: dequeue: seq=52 ts=3600 INTERMEDIATE
+sys={0.480000}, mono={0.480000}: clock_override_add
+sys={0.480000}, mono={0.480000}: dequeue: seq=53 ts=3760 INTERMEDIATE
+sys={0.500000}, mono={0.500000}: clock_override_add
+sys={0.500000}, mono={0.500000}: dequeue: seq=54 ts=3920 INTERMEDIATE
+sys={0.520000}, mono={0.520000}: clock_override_add
+sys={0.520000}, mono={0.520000}: dequeue: seq=55 ts=4080 INTERMEDIATE
+sys={0.540000}, mono={0.540000}: clock_override_add
+sys={0.540000}, mono={0.540000}: dequeue: seq=56 ts=4240 INTERMEDIATE
+sys={0.560000}, mono={0.560000}: clock_override_add
+sys={0.560000}, mono={0.560000}: dequeue: seq=57 ts=4400 INTERMEDIATE
+sys={0.580000}, mono={0.580000}: clock_override_add
+sys={0.580000}, mono={0.580000}: dequeue: seq=58 ts=4560 INTERMEDIATE
+sys={0.600000}, mono={0.600000}: clock_override_add
+sys={0.600000}, mono={0.600000}: dequeue: seq=59 ts=4720 INTERMEDIATE
+sys={0.620000}, mono={0.620000}: clock_override_add
+sys={0.620000}, mono={0.620000}: dequeue: seq=60 ts=4880 INTERMEDIATE
+sys={0.640000}, mono={0.640000}: clock_override_add
+sys={0.640000}, mono={0.640000}: dequeue: seq=61 ts=5040 INTERMEDIATE
+sys={0.660000}, mono={0.660000}: clock_override_add
+sys={0.660000}, mono={0.660000}: dequeue: seq=62 ts=5200 INTERMEDIATE
+sys={0.680000}, mono={0.680000}: clock_override_add
+sys={0.680000}, mono={0.680000}: dequeue: seq=63 ts=5360 INTERMEDIATE
+sys={0.700000}, mono={0.700000}: clock_override_add
+sys={0.700000}, mono={0.700000}: dequeue: seq=64 ts=5520 INTERMEDIATE
+sys={0.720000}, mono={0.720000}: clock_override_add
+sys={0.720000}, mono={0.720000}: dequeue: seq=65 ts=5680 INTERMEDIATE
+sys={0.740000}, mono={0.740000}: clock_override_add
+sys={0.740000}, mono={0.740000}: dequeue: seq=66 ts=5840 INTERMEDIATE
+sys={0.760000}, mono={0.760000}: clock_override_add
+sys={0.760000}, mono={0.760000}: dequeue: seq=67 ts=6000 INTERMEDIATE
+sys={0.780000}, mono={0.780000}: clock_override_add
+sys={0.780000}, mono={0.780000}: dequeue: seq=68 ts=6160 INTERMEDIATE
+sys={0.800000}, mono={0.800000}: clock_override_add
+sys={0.800000}, mono={0.800000}: dequeue: seq=69 ts=6320 INTERMEDIATE
+sys={0.820000}, mono={0.820000}: clock_override_add
+sys={0.820000}, mono={0.820000}: dequeue: seq=70 ts=6480 INTERMEDIATE
+sys={0.840000}, mono={0.840000}: clock_override_add
+sys={0.840000}, mono={0.840000}: dequeue: seq=71 ts=6640 INTERMEDIATE
+sys={0.860000}, mono={0.860000}: clock_override_add
+sys={0.860000}, mono={0.860000}: dequeue: seq=72 ts=6800 INTERMEDIATE
+sys={0.880000}, mono={0.880000}: clock_override_add
+sys={0.880000}, mono={0.880000}: dequeue: seq=73 ts=6960 INTERMEDIATE
+sys={0.900000}, mono={0.900000}: clock_override_add
+sys={0.900000}, mono={0.900000}: dequeue: seq=74 ts=7120 INTERMEDIATE
+sys={0.920000}, mono={0.920000}: clock_override_add
+sys={0.920000}, mono={0.920000}: dequeue: seq=75 ts=7280 INTERMEDIATE
+sys={0.940000}, mono={0.940000}: clock_override_add
+sys={0.940000}, mono={0.940000}: dequeue: seq=76 ts=7440 INTERMEDIATE
+sys={0.960000}, mono={0.960000}: clock_override_add
+sys={0.960000}, mono={0.960000}: dequeue: seq=77 ts=7600 INTERMEDIATE
+sys={0.980000}, mono={0.980000}: clock_override_add
+sys={0.980000}, mono={0.980000}: dequeue: seq=78 ts=7760 INTERMEDIATE
+sys={1.000000}, mono={1.000000}: clock_override_add
+sys={1.000000}, mono={1.000000}: dequeue: seq=79 ts=7920 INTERMEDIATE
+sys={1.020000}, mono={1.020000}: clock_override_add
+sys={1.020000}, mono={1.020000}: dequeue: seq=80 ts=8080 INTERMEDIATE
+sys={1.040000}, mono={1.040000}: clock_override_add
+sys={1.040000}, mono={1.040000}: dequeue: seq=81 ts=8240 INTERMEDIATE
+sys={1.060000}, mono={1.060000}: clock_override_add
+sys={1.060000}, mono={1.060000}: dequeue: seq=82 ts=8400 INTERMEDIATE
+sys={1.080000}, mono={1.080000}: clock_override_add
+sys={1.080000}, mono={1.080000}: dequeue: seq=83 ts=8560 INTERMEDIATE
+sys={1.100000}, mono={1.100000}: clock_override_add
+sys={1.100000}, mono={1.100000}: dequeue: seq=84 ts=8720 INTERMEDIATE
+sys={1.120000}, mono={1.120000}: clock_override_add
+sys={1.120000}, mono={1.120000}: dequeue: seq=85 ts=8880 INTERMEDIATE
+sys={1.140000}, mono={1.140000}: clock_override_add
+sys={1.140000}, mono={1.140000}: dequeue: seq=86 ts=9040 INTERMEDIATE
+sys={1.160000}, mono={1.160000}: clock_override_add
+sys={1.160000}, mono={1.160000}: dequeue: seq=87 ts=9200 INTERMEDIATE
+sys={1.180000}, mono={1.180000}: clock_override_add
+sys={1.180000}, mono={1.180000}: dequeue: seq=88 ts=9360 INTERMEDIATE
+sys={1.200000}, mono={1.200000}: clock_override_add
+sys={1.200000}, mono={1.200000}: dequeue: seq=89 ts=9520 INTERMEDIATE
+sys={1.220000}, mono={1.220000}: clock_override_add
+sys={1.220000}, mono={1.220000}: dequeue: seq=90 ts=9680 INTERMEDIATE
+sys={1.240000}, mono={1.240000}: clock_override_add
+sys={1.240000}, mono={1.240000}: dequeue: seq=91 ts=9840 INTERMEDIATE
+sys={1.260000}, mono={1.260000}: clock_override_add
+sys={1.260000}, mono={1.260000}: dequeue: seq=92 ts=10000 INTERMEDIATE
+sys={1.280000}, mono={1.280000}: clock_override_add
+sys={1.280000}, mono={1.280000}: dequeue: seq=93 ts=10160 INTERMEDIATE
+sys={1.300000}, mono={1.300000}: clock_override_add
+sys={1.300000}, mono={1.300000}: dequeue: seq=94 ts=10320 INTERMEDIATE
+sys={1.320000}, mono={1.320000}: clock_override_add
+sys={1.320000}, mono={1.320000}: dequeue: seq=95 ts=10480 INTERMEDIATE
+sys={1.340000}, mono={1.340000}: clock_override_add
+sys={1.340000}, mono={1.340000}: dequeue: seq=96 ts=10640 INTERMEDIATE
+sys={1.360000}, mono={1.360000}: clock_override_add
+sys={1.360000}, mono={1.360000}: dequeue: seq=97 ts=10800 INTERMEDIATE
+sys={1.380000}, mono={1.380000}: clock_override_add
+sys={1.380000}, mono={1.380000}: dequeue: seq=98 ts=10960 INTERMEDIATE
+sys={1.400000}, mono={1.400000}: clock_override_add
+sys={1.400000}, mono={1.400000}: dequeue: seq=99 ts=11120 INTERMEDIATE
+sys={1.420000}, mono={1.420000}: clock_override_add
+sys={1.420000}, mono={1.420000}: dequeue: seq=100 ts=11280 INTERMEDIATE
+sys={1.440000}, mono={1.440000}: clock_override_add
+sys={1.440000}, mono={1.440000}: dequeue: seq=101 ts=11440 INTERMEDIATE
+sys={1.460000}, mono={1.460000}: clock_override_add
+sys={1.460000}, mono={1.460000}: dequeue: seq=102 ts=11600 INTERMEDIATE
+sys={1.480000}, mono={1.480000}: clock_override_add
+sys={1.480000}, mono={1.480000}: dequeue: seq=103 ts=11760 INTERMEDIATE
+sys={1.500000}, mono={1.500000}: clock_override_add
+sys={1.500000}, mono={1.500000}: dequeue: seq=104 ts=11920 INTERMEDIATE
+sys={1.520000}, mono={1.520000}: clock_override_add
+sys={1.520000}, mono={1.520000}: dequeue: seq=105 ts=12080 INTERMEDIATE
+sys={1.540000}, mono={1.540000}: clock_override_add
+sys={1.540000}, mono={1.540000}: dequeue: seq=106 ts=12240 INTERMEDIATE
+sys={1.560000}, mono={1.560000}: clock_override_add
+sys={1.560000}, mono={1.560000}: dequeue: seq=107 ts=12400 INTERMEDIATE
+sys={1.580000}, mono={1.580000}: clock_override_add
+sys={1.580000}, mono={1.580000}: dequeue: seq=108 ts=12560 INTERMEDIATE
+sys={1.600000}, mono={1.600000}: clock_override_add
+sys={1.600000}, mono={1.600000}: dequeue: seq=109 ts=12720 INTERMEDIATE
+sys={1.620000}, mono={1.620000}: clock_override_add
+sys={1.620000}, mono={1.620000}: dequeue: seq=110 ts=12880 INTERMEDIATE
+sys={1.640000}, mono={1.640000}: clock_override_add
+sys={1.640000}, mono={1.640000}: dequeue: seq=111 ts=13040 INTERMEDIATE
+sys={1.660000}, mono={1.660000}: clock_override_add
+sys={1.660000}, mono={1.660000}: dequeue: seq=112 ts=13200 INTERMEDIATE
+sys={1.680000}, mono={1.680000}: clock_override_add
+sys={1.680000}, mono={1.680000}: dequeue: seq=113 ts=13360 INTERMEDIATE
+sys={1.700000}, mono={1.700000}: clock_override_add
+sys={1.700000}, mono={1.700000}: dequeue: seq=114 ts=13520 INTERMEDIATE
+sys={1.720000}, mono={1.720000}: clock_override_add
+sys={1.720000}, mono={1.720000}: dequeue: seq=115 ts=13680 INTERMEDIATE
+sys={1.740000}, mono={1.740000}: clock_override_add
+sys={1.740000}, mono={1.740000}: dequeue: seq=116 ts=13840 INTERMEDIATE
+sys={1.760000}, mono={1.760000}: clock_override_add
+sys={1.760000}, mono={1.760000}: dequeue: seq=117 ts=14000 INTERMEDIATE
+sys={1.780000}, mono={1.780000}: clock_override_add
+sys={1.780000}, mono={1.780000}: dequeue: seq=118 ts=14160 INTERMEDIATE
+sys={1.800000}, mono={1.800000}: clock_override_add
+sys={1.800000}, mono={1.800000}: dequeue: seq=119 ts=14320 INTERMEDIATE
+sys={1.820000}, mono={1.820000}: clock_override_add
+sys={1.820000}, mono={1.820000}: dequeue: seq=120 ts=14480 INTERMEDIATE
+sys={1.840000}, mono={1.840000}: clock_override_add
+sys={1.840000}, mono={1.840000}: dequeue: seq=121 ts=14640 INTERMEDIATE
+sys={1.860000}, mono={1.860000}: clock_override_add
+sys={1.860000}, mono={1.860000}: dequeue: seq=122 ts=14800 INTERMEDIATE
+sys={1.880000}, mono={1.880000}: clock_override_add
+sys={1.880000}, mono={1.880000}: dequeue: seq=123 ts=14960 INTERMEDIATE
+sys={1.900000}, mono={1.900000}: clock_override_add
+sys={1.900000}, mono={1.900000}: dequeue: seq=124 ts=15120 INTERMEDIATE
+sys={1.920000}, mono={1.920000}: clock_override_add
+sys={1.920000}, mono={1.920000}: dequeue: seq=125 ts=15280 INTERMEDIATE
+sys={1.940000}, mono={1.940000}: clock_override_add
+sys={1.940000}, mono={1.940000}: dequeue: seq=126 ts=15440 INTERMEDIATE
+sys={1.960000}, mono={1.960000}: clock_override_add
+sys={1.960000}, mono={1.960000}: dequeue: seq=127 ts=15600 INTERMEDIATE
+sys={1.980000}, mono={1.980000}: clock_override_add
+sys={1.980000}, mono={1.980000}: dequeue: seq=128 ts=15760 INTERMEDIATE
+sys={2.000000}, mono={2.000000}: clock_override_add
+sys={2.000000}, mono={2.000000}: dequeue: seq=129 ts=15920 INTERMEDIATE
+sys={2.020000}, mono={2.020000}: clock_override_add
+sys={2.020000}, mono={2.020000}: dequeue: seq=130 ts=16080 INTERMEDIATE
+sys={2.040000}, mono={2.040000}: clock_override_add
+sys={2.040000}, mono={2.040000}: dequeue: seq=131 ts=16240 INTERMEDIATE
+sys={2.060000}, mono={2.060000}: clock_override_add
+sys={2.060000}, mono={2.060000}: dequeue: seq=132 ts=16400 INTERMEDIATE
+sys={2.080000}, mono={2.080000}: clock_override_add
+sys={2.080000}, mono={2.080000}: dequeue: seq=133 ts=16560 INTERMEDIATE
+sys={2.100000}, mono={2.100000}: clock_override_add
+sys={2.100000}, mono={2.100000}: dequeue: seq=134 ts=16720 INTERMEDIATE
+sys={2.120000}, mono={2.120000}: clock_override_add
+sys={2.120000}, mono={2.120000}: dequeue: seq=135 ts=16880 INTERMEDIATE
+sys={2.140000}, mono={2.140000}: clock_override_add
+sys={2.140000}, mono={2.140000}: dequeue: seq=136 ts=17040 INTERMEDIATE
+sys={2.160000}, mono={2.160000}: clock_override_add
+sys={2.160000}, mono={2.160000}: dequeue: seq=137 ts=17200 INTERMEDIATE
+sys={2.180000}, mono={2.180000}: clock_override_add
+sys={2.180000}, mono={2.180000}: dequeue: seq=138 ts=17360 INTERMEDIATE
+sys={2.200000}, mono={2.200000}: clock_override_add
+sys={2.200000}, mono={2.200000}: dequeue: seq=139 ts=17520 INTERMEDIATE
+sys={2.200000}, mono={2.200000}: Done, checking threshold and cleaning
+sys={2.270000}, mono={2.270000}: clock_override_add
+sys={2.270000}, mono={2.270000}: dequeue: seq=140 ts=17680 INTERMEDIATE
+sys={2.270000}, mono={2.270000}: dequeue: seq=141 ts=17840 INTERMEDIATE
+sys={2.270000}, mono={2.270000}: dequeue: seq=142 ts=18000 INTERMEDIATE
+sys={2.270000}, mono={2.270000}: dequeue: seq=143 ts=18160 LATEST
+===test_seq_wraparound===
+sys={0.000000}, mono={0.000000}: clock_override_set
+sys={0.000000}, mono={0.000000}: enqueue 1st packet (seq=65534)
+sys={0.020000}, mono={0.020000}: clock_override_add
+sys={0.020000}, mono={0.020000}: enqueue 2nd packet (seq=65535)
+sys={0.040000}, mono={0.040000}: clock_override_add
+sys={0.040000}, mono={0.040000}: enqueue 3rd packet (seq=0, wraparound)
+sys={0.060000}, mono={0.060000}: clock_override_add
+sys={0.060000}, mono={0.060000}: enqueue 4th packet (seq=1)
+sys={0.080000}, mono={0.080000}: clock_override_add
+sys={0.080000}, mono={0.080000}: enqueue 5th packet (seq=2)
+sys={0.080000}, mono={0.080000}: dequeue 1st packet (seq=65534)
+sys={0.080000}, mono={0.080000}: dequeue: seq=65534 ts=560 INTERMEDIATE
+sys={0.100000}, mono={0.100000}: clock_override_add
+sys={0.100000}, mono={0.100000}: dequeue 2nd packet (seq=65535)
+sys={0.100000}, mono={0.100000}: dequeue: seq=65535 ts=720 INTERMEDIATE
+sys={0.120000}, mono={0.120000}: clock_override_add
+sys={0.120000}, mono={0.120000}: dequeue 3rd packet (seq=0, wraparound)
+sys={0.120000}, mono={0.120000}: dequeue: seq=0 ts=880 INTERMEDIATE
+sys={0.140000}, mono={0.140000}: clock_override_add
+sys={0.140000}, mono={0.140000}: dequeue 4th packet (seq=1)
+sys={0.140000}, mono={0.140000}: dequeue: seq=1 ts=1040 INTERMEDIATE
+sys={0.160000}, mono={0.160000}: clock_override_add
+sys={0.160000}, mono={0.160000}: dequeue 5th packet (seq=2)
+sys={0.160000}, mono={0.160000}: dequeue: seq=2 ts=1200 LATEST
+===test_timestamp_wraparound===
+sys={0.000000}, mono={0.000000}: clock_override_set
+sys={0.000000}, mono={0.000000}: enqueue 1st packet (ts=4294966990)
+sys={0.020000}, mono={0.020000}: clock_override_add
+sys={0.020000}, mono={0.020000}: enqueue 2nd packet (ts=4294967150)
+sys={0.040000}, mono={0.040000}: clock_override_add
+sys={0.040000}, mono={0.040000}: enqueue 3rd packet (ts=14, wraparound)
+sys={0.060000}, mono={0.060000}: clock_override_add
+sys={0.060000}, mono={0.060000}: enqueue 4th packet (ts=174)
+sys={0.080000}, mono={0.080000}: clock_override_add
+sys={0.080000}, mono={0.080000}: enqueue 5th packet (ts=334)
+sys={0.080000}, mono={0.080000}: dequeue 1st packet (ts=4294966990)
+sys={0.080000}, mono={0.080000}: dequeue: seq=33 ts=4294966990 INTERMEDIATE
+sys={0.100000}, mono={0.100000}: clock_override_add
+sys={0.100000}, mono={0.100000}: dequeue 2nd packet (ts=4294967150)
+sys={0.100000}, mono={0.100000}: dequeue: seq=34 ts=4294967150 INTERMEDIATE
+sys={0.120000}, mono={0.120000}: clock_override_add
+sys={0.120000}, mono={0.120000}: dequeue 3rd packet (ts=14, wraparound)
+sys={0.120000}, mono={0.120000}: dequeue: seq=35 ts=14 INTERMEDIATE
+sys={0.140000}, mono={0.140000}: clock_override_add
+sys={0.140000}, mono={0.140000}: dequeue 4th packet (ts=174)
+sys={0.140000}, mono={0.140000}: dequeue: seq=36 ts=174 INTERMEDIATE
+sys={0.160000}, mono={0.160000}: clock_override_add
+sys={0.160000}, mono={0.160000}: dequeue 5th packet (ts=334)
+sys={0.160000}, mono={0.160000}: dequeue: seq=37 ts=334 LATEST
+OK: Test passed
diff --git a/tests/testsuite.at b/tests/testsuite.at
index d0e55f6..81d40ba 100644
--- a/tests/testsuite.at
+++ b/tests/testsuite.at
@@ -6,3 +6,9 @@
 cat $abs_srcdir/osmux/osmux_test.ok > expout
 AT_CHECK([$abs_top_builddir/tests/osmux/osmux_test], [0], [expout], [ignore])
 AT_CLEANUP
+
+AT_SETUP([jibuf_test])
+AT_KEYWORDS([jibuf_test])
+cat $abs_srcdir/jibuf/jibuf_test.ok > expout
+AT_CHECK([$abs_top_builddir/tests/jibuf/jibuf_test], [0], [expout], [ignore])
+AT_CLEANUP

-- 
To view, visit https://gerrit.osmocom.org/7773
To unsubscribe, visit https://gerrit.osmocom.org/settings

Gerrit-MessageType: newchange
Gerrit-Change-Id: I9688ba9c4d5b733b9f29d0f15f73750f9271ef55
Gerrit-PatchSet: 1
Gerrit-Project: libosmo-netif
Gerrit-Branch: master
Gerrit-Owner: Pau Espin Pedrol <pes...@sysmocom.de>

Reply via email to