diff --git a/examples/loopback.py b/examples/loopback.py index 1b4d24a..8ac5c89 100644 --- a/examples/loopback.py +++ b/examples/loopback.py @@ -1,5 +1,5 @@ #!/usr/bin/env python3 -# -*- mode: python; indent-tabs-mode: t; c-basic-offset: 4; tab-width: 4 -*- +# -*- mode: python; indent-tabs-mode: t; c-basic-offset: 4; tab-width: 4; python-indent: 4 -*- import sys import select @@ -43,6 +43,10 @@ state_names = { PCM_STATE_SUSPENDED: 'PCM_STATE_SUSPENDED' } +type NamedProcess = tuple[str, subprocess.Popen] + +cmd_process : NamedProcess = None + def poll_desc(mask): return '|'.join([poll_names[bit] for bit, name in poll_names.items() if mask & bit]) @@ -108,20 +112,30 @@ class Loopback(object): @staticmethod def run_command(cmd): if cmd: - rc = subprocess.run(cmd) - if rc.returncode: - logging.warning(f'run {cmd}, return code {rc.returncode}') - else: - logging.info(f'run {cmd}, return code {rc.returncode}') + global cmd_process + cmd_process = (cmd, subprocess.Popen(cmd)) + + @staticmethod + def check_command_idle_handler(): + # an idle handler to watch the process created above + if cmd_process: + rc = cmd_process[1].poll() + if rc: + if rc.returncode: + logging.warning(f'run {cmd_process[0]}, return code {rc.returncode}') + else: + logging.info(f'run {cmd_process[0]}, return code {rc.returncode}') + cmd_process = None def register(self, reactor): + reactor.register_idle_handler(self.check_command_idle_handler) reactor.register_idle_handler(self.idle_handler) reactor.register(self.capture_pd, self) def start(self): assert self.state == None, "start must only be called once" # start reading data - size, data = self.capture.read() + size, _ = self.capture.read() if size: logging.warning(f'initial data discarded ({size} bytes)') @@ -187,10 +201,10 @@ class Loopback(object): if eventmask & select.POLLERR == select.POLLERR: # This is typically an underrun caused by the external command being run synchronously # (on the same thread) - logging.warning(f'POLLERR for capture device: {state_names[self.capture.state()]}') - self.capture.drop() - self.capture.read() - return False + state = self.capture.state() + if state == PCM_STATE_XRUN: + self.capture.drop() + logging.warning(f'POLLERR for capture device: {state_names[state]}') '''called when data is available for reading''' self.last_capture_event = datetime.now() @@ -208,12 +222,15 @@ class Loopback(object): # turn off playback after idle_close_timeout when there was only silence if datetime.now() - self.silence_start > timedelta(seconds=idle_close_timeout): + logging.debug('silence') self.set_state(LoopbackState.LISTENING) return False else: self.silence_start = None - if self.set_state(LoopbackState.PLAYING) != LoopbackState.PLAYING: + loop_state = self.set_state(LoopbackState.PLAYING) + if loop_state != LoopbackState.PLAYING: + logging.warning(f'setting state PLAYING failed: {str(loop_state)}') return False if data: @@ -235,7 +252,7 @@ class Loopback(object): if fd == self.capture_pd.fd: real_mask = self.capture.polldescriptors_revents([self.capture_pd.as_tuple()]) if real_mask: - return self.handle_capture_event(eventmask, name) + return self.handle_capture_event(real_mask, name) else: logging.debug('null capture event') return False diff --git a/src/alsaaudio.c b/src/alsaaudio.c index 017e0fb..781f38a 100644 --- a/src/alsaaudio.c +++ b/src/alsaaudio.c @@ -106,6 +106,9 @@ typedef struct { snd_pcm_t *handle; + // Debug logging + int state; + // Configurable parameters unsigned int channels; unsigned int rate; @@ -360,6 +363,40 @@ alsapcm_list(PyObject *self, PyObject *args, PyObject *kwds) return result; } +const char* state_name(int state) { + switch (state) { + case SND_PCM_STATE_OPEN: + return "SND_PCM_STATE_OPEN"; + case SND_PCM_STATE_SETUP: + return "SND_PCM_STATE_SETUP"; + case SND_PCM_STATE_PREPARED: + return "SND_PCM_STATE_PREPARED"; + case SND_PCM_STATE_RUNNING: + return "SND_PCM_STATE_RUNNING"; + case SND_PCM_STATE_XRUN: + return "SND_PCM_STATE_XRUN"; + case SND_PCM_STATE_DISCONNECTED: + return "SND_PCM_STATE_DISCONNECTED"; + case SND_PCM_STATE_DRAINING: + return "SND_PCM_STATE_DRAINING"; + case SND_PCM_STATE_PAUSED: + return "SND_PCM_STATE_PAUSED"; + case SND_PCM_STATE_SUSPENDED: + return "SND_PCM_STATE_SUSPENDED"; + default: + return "invalid PCM state"; + } +} + +void print_state(alsapcm_t *self) +{ + int state = snd_pcm_state(self->handle); + if (state != self->state) { + printf("[%s %s] %s->%s\n", self->cardname, self->pcmtype == SND_PCM_STREAM_CAPTURE ? "capture" : "playback", state_name(self->state), state_name(state)); + self->state = state; + } +} + static int alsapcm_setup(alsapcm_t *self) { int res,dir; @@ -405,6 +442,8 @@ static int alsapcm_setup(alsapcm_t *self) self->framesize = self->channels * snd_pcm_format_physical_width(self->format)/8; + self->state = snd_pcm_state(self->handle); + return res; } @@ -1347,7 +1386,6 @@ static PyObject * alsapcm_read(alsapcm_t *self, PyObject *args) { snd_pcm_state_t state; - int res; int size = self->framesize * self->periodsize; int sizeout = 0; PyObject *buffer_obj, *tuple_obj, *res_obj; @@ -1380,11 +1418,19 @@ alsapcm_read(alsapcm_t *self, PyObject *args) buffer = PyBytes_AS_STRING(buffer_obj); #endif + int res = 0; + + print_state(self); + // After drop() and drain(), we need to prepare the stream again. // Note that fresh streams are already prepared by snd_pcm_hw_params(). state = snd_pcm_state(self->handle); - if ((state != SND_PCM_STATE_SETUP) || - !(res = snd_pcm_prepare(self->handle))) { + if (state == SND_PCM_STATE_SETUP) { + res = snd_pcm_prepare(self->handle); + printf("[%s] called snd_pcm_prepare: %d\n", self->cardname, res); + } + + if (res == 0) { Py_BEGIN_ALLOW_THREADS res = snd_pcm_readi(self->handle, buffer, self->periodsize); @@ -1488,6 +1534,8 @@ static PyObject *alsapcm_write(alsapcm_t *self, PyObject *args) return NULL; } + print_state(self); + int res; // After drop() and drain(), we need to prepare the stream again. // Note that fresh streams are already prepared by snd_pcm_hw_params(). @@ -1577,6 +1625,9 @@ static PyObject *alsapcm_pause(alsapcm_t *self, PyObject *args) return NULL; } + + print_state(self); + return PyLong_FromLong(res); } @@ -1599,6 +1650,8 @@ static PyObject *alsapcm_drop(alsapcm_t *self) return NULL; } + print_state(self); + return PyLong_FromLong(res); } @@ -1623,6 +1676,8 @@ static PyObject *alsapcm_drain(alsapcm_t *self) return NULL; } + print_state(self); + return PyLong_FromLong(res); }