diff --git a/run_latency_test.sh b/run_latency_test.sh new file mode 100755 index 0000000..aefec0c --- /dev/null +++ b/run_latency_test.sh @@ -0,0 +1,137 @@ +#!/bin/bash +# +# Tested on Ubuntu 18.04 +# + +function cleanup { +#kill and wait for previous daemon instances to exit + sudo killall -q ptp4l + killall -q aes67-daemon + while killall -0 aes67-daemon 2>/dev/null ; do + sleep 1 + done +} + +function usage { + echo 'Usage run_latenvy_test.sh sample_format sample_rate channels duration' >&2 + echo ' sample_format can be one of S16_LE, S24_3LE, S32_LE' >&2 + echo ' sample_rate can be one of 44100, 48000, 96000' >&2 + echo ' channels can be one of 1, 2, 4' >&2 + echo ' duration in seconds' >&2 + exit 1 +} + + +if [ "$#" -ne 4 ]; then + usage +fi + +if ! [ -x "$(command -v /usr/sbin/ptp4l)" ]; then + echo 'Error: ptp4l is not installed.' >&2 + exit 1 +fi + +if ! [ -x "$(command -v arecord)" ]; then + echo 'Error: arecord is not installed.' >&2 + exit 1 +fi + +if ! [ -x "$(command -v aplay)" ]; then + echo 'Error: aplay is not installed.' >&2 + exit 1 +fi + +if ! [ -x "$(command -v ./daemon/aes67-daemon)" ]; then + echo 'Error: aes67-daemon is not compiled.' >&2 + exit 1 +fi + +if ! [ -r "3rdparty/ravenna-alsa-lkm/driver/MergingRavennaALSA.ko" ]; then + echo 'Error: MergingRavennaALSA.ko module is not compiled.' >&2 + exit 1 +fi + +cd test +echo 'Compiling tools ...' >&2 +make +cd .. + +SAMPLE_FORMAT=$1 +SAMPLE_RATE=$2 +CHANNELS=$3 +DURATION=$4 + +if [ $SAMPLE_FORMAT == "S16_LE" ]; then + CODEC="L16" +elif [ $SAMPLE_FORMAT == "S24_3LE" ]; then + CODEC="L24" +elif [ $SAMPLE_FORMAT == "S32_LE" ] ; then + CODEC="AM824" +else + usage +fi + +if [ $SAMPLE_RATE == "44100" ]; then + PTIME="1.08843537415" +elif [ $SAMPLE_RATE == "48000" ]; then + PTIME="1" +elif [ $SAMPLE_RATE == "96000" ]; then + PTIME="0.5" +else + usage +fi + +MAP="[ " +for (( ch=0; ch<$CHANNELS; ch++ )) +do + MAP+=$ch + if (( ch != ($CHANNELS - 1) )); then + MAP+="," + fi +done +MAP+=" ]" + +echo 'Creating configuration files ..' >&2 +sed 's/48000/'"$SAMPLE_RATE"'/g;s/status.json/status_.json/g;' test/daemon.conf > test/daemon_.conf +sed 's/\/2/\/'"$CHANNELS"'/g;s/48000/'"$SAMPLE_RATE"'/g;s/L24/'"$CODEC"'/g;s/ptime:1/ptime:'"$PTIME"'/;s/\[ 0, 1 \]/'"$MAP"'/g' test/status.json > test/status_.json + +trap cleanup EXIT + +#configure system parms +sudo sysctl -w net/ipv4/igmp_max_memberships=66 + +if [ -x /usr/bin/pulseaudio ]; then + #stop pulseaudio, this seems to open/close ALSA continuosly + echo autospawn = no > $HOME/.config/pulse/client.conf + pulseaudio --kill >/dev/null 2>&1 + rm $HOME/.config/pulse/client.conf + #disable pulseaudio + systemctl --user stop pulseaudio.socket > /dev/null 2>&1 + systemctl --user stop pulseaudio.sservice > /dev/null 2>&1 +fi + +#uninstall kernel module +if sudo lsmod | grep MergingRavennaALSA > /dev/null 2>&1 ; then + sudo rmmod MergingRavennaALSA +fi + +#install kernel module +sudo insmod 3rdparty/ravenna-alsa-lkm/driver/MergingRavennaALSA.ko + +cleanup + +echo "Starting PTP master ..." +sudo /usr/sbin/ptp4l -i lo -l7 -E -S & + +echo "Starting AES67 daemon ..." +./daemon/aes67-daemon -c ./test/daemon_.conf & + +echo "Waiting for PTP slave to sync ..." +sleep 30 + +echo "Running 10 secs latency test" +cd test +./latency -P hw:RAVENNA -C hw:RAVENNA -f $SAMPLE_FORMAT -r $SAMPLE_RATE -c $CHANNELS -M 128 -m 128 -s $DURATION +cd .. + +echo "Terminating processes ..." diff --git a/test/Makefile b/test/Makefile index 55ccbe1..09ff99a 100644 --- a/test/Makefile +++ b/test/Makefile @@ -1,8 +1,11 @@ CXX=g++ CC=g++ -all: check createtest +LIBS=-lpthread -lasound +all: check createtest latency createtest: createtest.o check: check.o +latency: latency.o + $(CXX) $< -o latency $(LIBS) clean: rm *.o - rm check createtest + rm check createtest latency diff --git a/test/latency.cc b/test/latency.cc new file mode 100644 index 0000000..b1855d8 --- /dev/null +++ b/test/latency.cc @@ -0,0 +1,742 @@ +/* + * Latency test program + * + * Author: Jaroslav Kysela + * + * Author of bandpass filter sweep effect: + * Maarten de Boer + * + * This small demo program can be used for measuring latency between + * capture and playback. This latency is measured from driver (diff when + * playback and capture was started). Scheduler is set to SCHED_RR. + * + * + * 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. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program; if not, write to the Free Software + * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA + * + */ + +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include + +static unsigned char header[4] = { 0xff, 0xff, 0xff, 0xff }; +const char *pdevice = "hw:0,0"; +const char *cdevice = "hw:0,0"; +snd_pcm_format_t format = SND_PCM_FORMAT_S16_LE; +int rate = 22050; +int channels = 2; +int buffer_size = 0; /* auto */ +int period_size = 0; /* auto */ +int latency_min = 32; /* in frames / 2 */ +int latency_max = 2048; /* in frames / 2 */ +int loop_sec = 30; /* seconds */ +int block = 0; /* block mode */ +int use_poll = 0; +int resample = 1; +unsigned long loop_limit; +uint64_t end_to_end_latency = 0; +uint64_t end_to_end_samples = 0; + +snd_output_t *output = NULL; + +int setparams_stream(snd_pcm_t *handle, + snd_pcm_hw_params_t *params, + const char *id) +{ + int err; + unsigned int rrate; + + err = snd_pcm_hw_params_any(handle, params); + if (err < 0) { + printf("Broken configuration for %s PCM: no configurations available: %s\n", snd_strerror(err), id); + return err; + } + err = snd_pcm_hw_params_set_rate_resample(handle, params, resample); + if (err < 0) { + printf("Resample setup failed for %s (val %i): %s\n", id, resample, snd_strerror(err)); + return err; + } + err = snd_pcm_hw_params_set_access(handle, params, SND_PCM_ACCESS_RW_INTERLEAVED); + if (err < 0) { + printf("Access type not available for %s: %s\n", id, snd_strerror(err)); + return err; + } + err = snd_pcm_hw_params_set_format(handle, params, format); + if (err < 0) { + printf("Sample format not available for %s: %s\n", id, snd_strerror(err)); + return err; + } + err = snd_pcm_hw_params_set_channels(handle, params, channels); + if (err < 0) { + printf("Channels count (%i) not available for %s: %s\n", channels, id, snd_strerror(err)); + return err; + } + rrate = rate; + err = snd_pcm_hw_params_set_rate_near(handle, params, &rrate, 0); + if (err < 0) { + printf("Rate %iHz not available for %s: %s\n", rate, id, snd_strerror(err)); + return err; + } + if ((int)rrate != rate) { + printf("Rate doesn't match (requested %iHz, get %iHz)\n", rate, err); + return -EINVAL; + } + return 0; +} + +int setparams_bufsize(snd_pcm_t *handle, + snd_pcm_hw_params_t *params, + snd_pcm_hw_params_t *tparams, + snd_pcm_uframes_t bufsize, + const char *id) +{ + int err; + snd_pcm_uframes_t periodsize; + + snd_pcm_hw_params_copy(params, tparams); + periodsize = bufsize * 2; + err = snd_pcm_hw_params_set_buffer_size_near(handle, params, &periodsize); + if (err < 0) { + printf("Unable to set buffer size %li for %s: %s\n", bufsize * 2, id, snd_strerror(err)); + return err; + } + if (period_size > 0) + periodsize = period_size; + else + periodsize /= 2; + err = snd_pcm_hw_params_set_period_size_near(handle, params, &periodsize, 0); + if (err < 0) { + printf("Unable to set period size %li for %s: %s\n", periodsize, id, snd_strerror(err)); + return err; + } + return 0; +} + +int setparams_set(snd_pcm_t *handle, + snd_pcm_hw_params_t *params, + snd_pcm_sw_params_t *swparams, + const char *id) +{ + int err; + snd_pcm_uframes_t val; + + err = snd_pcm_hw_params(handle, params); + if (err < 0) { + printf("Unable to set hw params for %s: %s\n", id, snd_strerror(err)); + return err; + } + err = snd_pcm_sw_params_current(handle, swparams); + if (err < 0) { + printf("Unable to determine current swparams for %s: %s\n", id, snd_strerror(err)); + return err; + } + err = snd_pcm_sw_params_set_start_threshold(handle, swparams, 0x7fffffff); + if (err < 0) { + printf("Unable to set start threshold mode for %s: %s\n", id, snd_strerror(err)); + return err; + } + if (!block) + val = 4; + else + snd_pcm_hw_params_get_period_size(params, &val, NULL); + err = snd_pcm_sw_params_set_avail_min(handle, swparams, val); + if (err < 0) { + printf("Unable to set avail min for %s: %s\n", id, snd_strerror(err)); + return err; + } + err = snd_pcm_sw_params(handle, swparams); + if (err < 0) { + printf("Unable to set sw params for %s: %s\n", id, snd_strerror(err)); + return err; + } + return 0; +} + +int setparams(snd_pcm_t *phandle, snd_pcm_t *chandle, int *bufsize) +{ + int err, last_bufsize = *bufsize; + snd_pcm_hw_params_t *pt_params, *ct_params; /* templates with rate, format and channels */ + snd_pcm_hw_params_t *p_params, *c_params; + snd_pcm_sw_params_t *p_swparams, *c_swparams; + snd_pcm_uframes_t p_size, c_size, p_psize, c_psize; + unsigned int p_time, c_time; + unsigned int val; + + snd_pcm_hw_params_alloca(&p_params); + snd_pcm_hw_params_alloca(&c_params); + snd_pcm_hw_params_alloca(&pt_params); + snd_pcm_hw_params_alloca(&ct_params); + snd_pcm_sw_params_alloca(&p_swparams); + snd_pcm_sw_params_alloca(&c_swparams); + if ((err = setparams_stream(phandle, pt_params, "playback")) < 0) { + printf("Unable to set parameters for playback stream: %s\n", snd_strerror(err)); + exit(0); + } + if ((err = setparams_stream(chandle, ct_params, "capture")) < 0) { + printf("Unable to set parameters for playback stream: %s\n", snd_strerror(err)); + exit(0); + } + + if (buffer_size > 0) { + *bufsize = buffer_size; + goto __set_it; + } + + __again: + if (buffer_size > 0) + return -1; + if (last_bufsize == *bufsize) + *bufsize += 4; + last_bufsize = *bufsize; + if (*bufsize > latency_max) + return -1; + __set_it: + + if ((err = setparams_bufsize(phandle, p_params, pt_params, *bufsize, "playback")) < 0) { + printf("Unable to set sw parameters for playback stream: %s\n", snd_strerror(err)); + exit(0); + } + if ((err = setparams_bufsize(chandle, c_params, ct_params, *bufsize, "capture")) < 0) { + printf("Unable to set sw parameters for playback stream: %s\n", snd_strerror(err)); + exit(0); + } + + snd_pcm_hw_params_get_period_size(p_params, &p_psize, NULL); + if (p_psize > (unsigned int)*bufsize) + *bufsize = p_psize; + snd_pcm_hw_params_get_period_size(c_params, &c_psize, NULL); + if (c_psize > (unsigned int)*bufsize) + *bufsize = c_psize; + snd_pcm_hw_params_get_period_time(p_params, &p_time, NULL); + snd_pcm_hw_params_get_period_time(c_params, &c_time, NULL); + if (p_time != c_time) + goto __again; + + //printf("p period_time = %u\n", p_time); + //printf("p period_size = %lu\n", p_size); + //printf("c period_time = %u\n", c_time); + //printf("c period_size = %lu\n", c_size); + + snd_pcm_hw_params_get_buffer_size(p_params, &p_size); + if (p_psize * 2 < p_size) { + snd_pcm_hw_params_get_periods_min(p_params, &val, NULL); + //printf("p period_min = %u\n", val); + if (val > 2) { + printf("playback device does not support 2 periods per buffer\n"); + //exit(0); + } + //goto __again; + } + snd_pcm_hw_params_get_buffer_size(c_params, &c_size); + if (c_psize * 2 < c_size) { + snd_pcm_hw_params_get_periods_min(c_params, &val, NULL); + //printf("c period_min = %u\n", val); + if (val > 2 ) { + printf("capture device does not support 2 periods per buffer\n"); + //exit(0); + } + //goto __again; + } + if ((err = setparams_set(phandle, p_params, p_swparams, "playback")) < 0) { + printf("Unable to set sw parameters for playback stream: %s\n", snd_strerror(err)); + exit(0); + } + if ((err = setparams_set(chandle, c_params, c_swparams, "capture")) < 0) { + printf("Unable to set sw parameters for playback stream: %s\n", snd_strerror(err)); + exit(0); + } + + if ((err = snd_pcm_prepare(phandle)) < 0) { + printf("Prepare error: %s\n", snd_strerror(err)); + exit(0); + } + + snd_pcm_dump(phandle, output); + snd_pcm_dump(chandle, output); + fflush(stdout); + return 0; +} + +void showstat(snd_pcm_t *handle, size_t frames) +{ + int err; + snd_pcm_status_t *status; + + snd_pcm_status_alloca(&status); + if ((err = snd_pcm_status(handle, status)) < 0) { + printf("Stream status error: %s\n", snd_strerror(err)); + exit(0); + } + printf("*** frames = %li ***\n", (long)frames); + snd_pcm_status_dump(status, output); +} + +void showlatency(size_t latency) +{ + double d; + latency *= 2; + d = (double)latency / (double)rate; + printf("Trying latency %li frames, %.3fus, %.6fms (%.4fHz)\n", (long)latency, d * 1000000, d * 1000, (double)1 / d); +} + +void showinmax(size_t in_max) +{ + double d; + + printf("Maximum read: %li frames\n", (long)in_max); + d = (double)in_max / (double)rate; + printf("Maximum read latency: %.3fus, %.6fms (%.4fHz)\n", d * 1000000, d * 1000, (double)1 / d); +} + +void gettimestamp(snd_pcm_t *handle, snd_timestamp_t *timestamp) +{ + int err; + snd_pcm_status_t *status; + + snd_pcm_status_alloca(&status); + if ((err = snd_pcm_status(handle, status)) < 0) { + printf("Stream status error: %s\n", snd_strerror(err)); + exit(0); + } + snd_pcm_status_get_trigger_tstamp(status, timestamp); +} + +void setscheduler(void) +{ + struct sched_param sched_param; + + if (sched_getparam(0, &sched_param) < 0) { + printf("Scheduler getparam failed...\n"); + return; + } + sched_param.sched_priority = sched_get_priority_max(SCHED_RR); + if (!sched_setscheduler(0, SCHED_RR, &sched_param)) { + printf("Scheduler set to Round Robin with priority %i...\n", sched_param.sched_priority); + fflush(stdout); + return; + } + printf("!!!Scheduler set to Round Robin with priority %i FAILED!!!\n", sched_param.sched_priority); +} + +long timediff(snd_timestamp_t t1, snd_timestamp_t t2) +{ + signed long l; + + t1.tv_sec -= t2.tv_sec; + l = (signed long) t1.tv_usec - (signed long) t2.tv_usec; + if (l < 0) { + t1.tv_sec--; + l = 1000000 + l; + l %= 1000000; + } + return (t1.tv_sec * 1000000) + l; +} + +long readbuf(snd_pcm_t *handle, char *buf, long len, size_t *frames, size_t *max) +{ + long r; + + if (!block) { + do { + r = snd_pcm_readi(handle, buf, len); + } while (r == -EAGAIN); + if (r > 0) { + *frames += r; + if ((long)*max < r) + *max = r; + } + // printf("read = %li\n", r); + } else { + int frame_bytes = (snd_pcm_format_width(format) / 8) * channels; + do { + r = snd_pcm_readi(handle, buf, len); + if (r > 0) { + buf += r * frame_bytes; + len -= r; + *frames += r; + if ((long)*max < r) + *max = r; + } + // printf("r = %li, len = %li\n", r, len); + } while (r >= 1 && len > 0); + } + + + uint64_t sentMs, recvMs = + std::chrono::duration_cast( + std::chrono::system_clock::now().time_since_epoch()).count(); + + for (int i = 0; i < (r - 12); i++) { + if (!memcmp(buf + i, header, 4)) { + memcpy(&sentMs, buf + i + 4, 8); + //printf("elpased %lu ms\n", recvMs - sentMs); + + if ((recvMs - sentMs) < 1000) { + end_to_end_latency += recvMs - sentMs; + end_to_end_samples++; + } + } + } + + // showstat(handle, 0); + return r; +} + +long writebuf(snd_pcm_t *handle, char *buf, long len, size_t *frames) +{ + long r; + int frame_bytes = (snd_pcm_format_width(format) / 8) * channels; + + uint64_t ms = + std::chrono::duration_cast( + std::chrono::system_clock::now().time_since_epoch()).count(); + + memcpy(buf, header, 4); + memcpy(buf + 4, &ms, sizeof(ms)); + + while (len > 0) { + r = snd_pcm_writei(handle, buf, len); + if (r == -EAGAIN) + continue; + // printf("write = %li\n", r); + if (r < 0) + return r; + // showstat(handle, 0); + buf += r * frame_bytes; + len -= r; + *frames += r; + } + return 0; +} + +#define FILTERSWEEP_LFO_CENTER 2000. +#define FILTERSWEEP_LFO_DEPTH 1800. +#define FILTERSWEEP_LFO_FREQ 0.2 +#define FILTER_BANDWIDTH 50 + +/* filter the sweep variables */ +float lfo,dlfo,fs,fc,BW,C,D,a0,a1,a2,b1,b2,*x[3],*y[3]; + +void applyeffect(char* buffer,int r) +{ + short* samples = (short*) buffer; + int i; + for (i=0;i2.*M_PI) lfo -= 2.*M_PI; + C = 1./tan(M_PI*BW/fs); + D = 2.*cos(2*M_PI*fc/fs); + a0 = 1./(1.+C); + a1 = 0; + a2 = -a0; + b1 = -C*D*a0; + b2 = (C-1)*a0; + + for (chn=0;chn= 4 ? err : 4; + if (latency_max < latency_min) + latency_max = latency_min; + break; + case 'M': + err = atoi(optarg) / 2; + latency_max = latency_min > err ? latency_min : err; + break; + case 'f': + format = snd_pcm_format_value(optarg); + if (format == SND_PCM_FORMAT_UNKNOWN) { + printf("Unknown format, setting to default S16_LE\n"); + format = SND_PCM_FORMAT_S16_LE; + } + break; + case 'c': + err = atoi(optarg); + channels = err >= 1 && err < 1024 ? err : 1; + break; + case 'r': + err = atoi(optarg); + rate = err >= 4000 && err < 200000 ? err : 44100; + break; + case 'B': + err = atoi(optarg); + buffer_size = err >= 32 && err < 200000 ? err : 0; + break; + case 'E': + err = atoi(optarg); + period_size = err >= 32 && err < 200000 ? err : 0; + break; + case 's': + err = atoi(optarg); + loop_sec = err >= 1 && err <= 100000 ? err : 30; + break; + case 'b': + block = 1; + break; + case 'p': + use_poll = 1; + break; + case 'e': + effect = 1; + break; + case 'n': + resample = 0; + break; + } + } + + if (morehelp) { + help(); + return 0; + } + err = snd_output_stdio_attach(&output, stdout, 0); + if (err < 0) { + printf("Output failed: %s\n", snd_strerror(err)); + return 0; + } + + loop_limit = loop_sec * rate; + latency = latency_min - 4; + buffer = (char*)malloc((latency_max * snd_pcm_format_width(format) / 8) * 2); + + setscheduler(); + + printf("Playback device is %s\n", pdevice); + printf("Capture device is %s\n", cdevice); + printf("Parameters are %iHz, %s, %i channels, %s mode\n", rate, snd_pcm_format_name(format), channels, block ? "blocking" : "non-blocking"); + printf("Poll mode: %s\n", use_poll ? "yes" : "no"); + printf("Loop limit is %lu frames, minimum latency = %i, maximum latency = %i\n", loop_limit, latency_min * 2, latency_max * 2); + + if ((err = snd_pcm_open(&phandle, pdevice, SND_PCM_STREAM_PLAYBACK, block ? 0 : SND_PCM_NONBLOCK)) < 0) { + printf("Playback open error: %s\n", snd_strerror(err)); + return 0; + } + if ((err = snd_pcm_open(&chandle, cdevice, SND_PCM_STREAM_CAPTURE, block ? 0 : SND_PCM_NONBLOCK)) < 0) { + printf("Record open error: %s\n", snd_strerror(err)); + return 0; + } + + /* initialize the filter sweep variables */ + if (effect) { + fs = (float) rate; + BW = FILTER_BANDWIDTH; + + lfo = 0; + dlfo = 2.*M_PI*FILTERSWEEP_LFO_FREQ/fs; + + x[0] = (float*) malloc(channels*sizeof(float)); + x[1] = (float*) malloc(channels*sizeof(float)); + x[2] = (float*) malloc(channels*sizeof(float)); + y[0] = (float*) malloc(channels*sizeof(float)); + y[1] = (float*) malloc(channels*sizeof(float)); + y[2] = (float*) malloc(channels*sizeof(float)); + } + + while (1) { + frames_in = frames_out = 0; + if (setparams(phandle, chandle, &latency) < 0) + break; + showlatency(latency); + if ((err = snd_pcm_link(chandle, phandle)) < 0) { + printf("Streams link error: %s\n", snd_strerror(err)); + exit(0); + } + if (snd_pcm_format_set_silence(format, buffer, latency*channels) < 0) { + fprintf(stderr, "silence error\n"); + break; + } + if (writebuf(phandle, buffer, latency, &frames_out) < 0) { + fprintf(stderr, "write error\n"); + break; + } + if (writebuf(phandle, buffer, latency, &frames_out) < 0) { + fprintf(stderr, "write error\n"); + break; + } + + if ((err = snd_pcm_start(chandle)) < 0) { + printf("Go error: %s\n", snd_strerror(err)); + exit(0); + } + gettimestamp(phandle, &p_tstamp); + gettimestamp(chandle, &c_tstamp); +#if 0 + printf("Playback:\n"); + showstat(phandle, frames_out); + printf("Capture:\n"); + showstat(chandle, frames_in); +#endif + + ok = 1; + in_max = 0; + while (ok && frames_in < loop_limit) { + if (use_poll) { + /* use poll to wait for next event */ + snd_pcm_wait(chandle, 1000); + } + if ((r = readbuf(chandle, buffer, latency, &frames_in, &in_max)) < 0) + ok = 0; + else { + if (effect) + applyeffect(buffer,r); + if (writebuf(phandle, buffer, r, &frames_out) < 0) + ok = 0; + } + } + if (ok) + printf("Success\n"); + else + printf("Failure\n"); + printf("Playback:\n"); + showstat(phandle, frames_out); + printf("Capture:\n"); + showstat(chandle, frames_in); + showinmax(in_max); + if (p_tstamp.tv_sec == c_tstamp.tv_sec && + p_tstamp.tv_usec == c_tstamp.tv_usec) + printf("Hardware sync\n"); + snd_pcm_drop(chandle); + snd_pcm_nonblock(phandle, 0); + snd_pcm_drain(phandle); + snd_pcm_nonblock(phandle, !block ? 1 : 0); + if (ok) { +#if 1 + printf("Playback time = %li.%i, Record time = %li.%i, diff = %li\n", + p_tstamp.tv_sec, + (int)p_tstamp.tv_usec, + c_tstamp.tv_sec, + (int)c_tstamp.tv_usec, + timediff(p_tstamp, c_tstamp)); +#endif + break; + } + snd_pcm_unlink(chandle); + snd_pcm_hw_free(phandle); + snd_pcm_hw_free(chandle); + } + + printf("End to end latency: %lu ms\n", end_to_end_latency / end_to_end_samples); + snd_pcm_close(phandle); + snd_pcm_close(chandle); + return 0; +} +