From 25c20e5534f6671a27b0218d6c0882e1fbb46e06 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Daniel=20Ekl=C3=B6f?= Date: Sat, 21 Aug 2021 10:52:12 +0200 Subject: [PATCH 1/4] module/alsa: use inotify on /dev/snd instead of a poll timeout MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit While waiting for the configured ALSA card to become available, use inotify and watch for CREATE events on /dev/snd instead of polling (using a timeout in the poll(3) call). Note that we don’t know the actual names of the files that (will) be created. This means: * Every time we see a CREATE event on /dev/snd, we *try* to connect to ALSA. If we fail, we go back to watching /dev/snd again. * ALSA (not yambar) will log an error message each time we fail. --- modules/alsa.c | 118 +++++++++++++++++++++++++++++-------------------- 1 file changed, 70 insertions(+), 48 deletions(-) diff --git a/modules/alsa.c b/modules/alsa.c index 54b9124..aa985b0 100644 --- a/modules/alsa.c +++ b/modules/alsa.c @@ -2,6 +2,7 @@ #include #include #include +#include #include @@ -315,79 +316,100 @@ err: static int run(struct module *mod) { - static const int min_timeout_ms = 500; - static const int max_timeout_ms = 30000; - int timeout_ms = min_timeout_ms; + int ret = 1; + + int wd = -1; + int ifd = inotify_init(); + if (ifd < 0) { + LOG_ERRNO("failed to inotify"); + return 1; + } while (true) { enum run_state state = run_while_online(mod); switch (state) { case RUN_DONE: - return 0; - - case RUN_ERROR: - return 1; - - case RUN_FAILED_CONNECT: - timeout_ms *= 2; + ret = 0; break; + case RUN_ERROR: + ret = 1; + break; + + case RUN_FAILED_CONNECT: case RUN_DISCONNECTED: - timeout_ms = min_timeout_ms; break; } - if (timeout_ms > max_timeout_ms) - timeout_ms = max_timeout_ms; - - struct timeval now; - gettimeofday(&now, NULL); - - struct timeval timeout = { - .tv_sec = timeout_ms / 1000, - .tv_usec = (timeout_ms % 1000) * 1000, - }; - - struct timeval deadline; - timeradd(&now, &timeout, &deadline); - - LOG_DBG("timeout is now %dms", timeout_ms); + wd = inotify_add_watch(ifd, "/dev/snd", IN_CREATE); + if (wd < 0) { + LOG_ERRNO("failed to create inotify watcher for /dev/snd"); + ret = 1; + break; + } while (true) { - - struct timeval n; - gettimeofday(&n, NULL); - - struct timeval left; - timersub(&deadline, &n, &left); - - int poll_timeout = timercmp(&left, &(struct timeval){0}, <) - ? 0 - : left.tv_sec * 1000 + left.tv_usec / 1000; - - LOG_DBG( - "polling for alsa device to become available (timeout=%dms)", - poll_timeout); - - struct pollfd fds[] = {{.fd = mod->abort_fd, .events = POLLIN}}; - int r = poll(fds, 1, poll_timeout); + struct pollfd fds[] = {{.fd = mod->abort_fd, .events = POLLIN}, + {.fd = ifd, .events = POLLIN}}; + int r = poll(fds, sizeof(fds) / sizeof(fds[0]), -1); if (r < 0) { if (errno == EINTR) continue; LOG_ERRNO("failed to poll"); - return 1; + ret = 1; + goto out; } - if (fds[0].revents & POLLIN) - return 0; + if (fds[0].revents & POLLIN) { + ret = 0; + goto out; + } - assert(r == 0); - break; + if (fds[1].revents & POLLIN) { + char buf[1024]; + ssize_t len = read(ifd, buf, sizeof(buf)); + + if (len < 0) { + LOG_ERRNO("failed to read inotify events"); + ret = 1; + goto out; + } + + if (len == 0) { + LOG_ERR("inotify FD closed"); + ret = 1; + goto out; + } + + /* Consume inotify data */ + bool have_create_event = false; + for (const char *ptr = buf; ptr < buf + len; ) { + const struct inotify_event *e = (const struct inotify_event *)ptr; + if (e->mask & IN_CREATE) { + LOG_DBG("inotify: CREATED: /dev/snd/%.*s", e->len, e->name); + have_create_event = true; + } + ptr += sizeof(*e) + e->len; + } + + if (have_create_event) { + inotify_rm_watch(ifd, wd); + wd = -1; + break; + } + } } } + +out: + if (wd >= 0) + inotify_rm_watch(ifd, wd); + if (ifd >= 0) + close (ifd); + return ret; } static struct module * From 5af070ee1db524e914799e2116363a6c38adbed8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Daniel=20Ekl=C3=B6f?= Date: Sat, 21 Aug 2021 11:08:06 +0200 Subject: [PATCH 2/4] log: LOG_ERRNO: include numeric value of errno --- log.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/log.c b/log.c index c1adcd0..467b6fd 100644 --- a/log.c +++ b/log.c @@ -84,7 +84,7 @@ _log(enum log_class log_class, const char *module, const char *file, int lineno, vfprintf(stderr, fmt, va); if (sys_errno != 0) - fprintf(stderr, ": %s", strerror(sys_errno)); + fprintf(stderr, ": %s (%d)", strerror(sys_errno), sys_errno); fputc('\n', stderr); } From 360e1fbada721a21a725b003a928263f49aa5b93 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Daniel=20Ekl=C3=B6f?= Date: Sat, 21 Aug 2021 11:08:45 +0200 Subject: [PATCH 3/4] =?UTF-8?q?module/alsa:=20don=E2=80=99t=20re-create=20?= =?UTF-8?q?the=20/dev/snd=20inotify=20watcher=20after=20each=20connect=20f?= =?UTF-8?q?ailure?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit When e.g. a USB soundcard is inserted, we get several CREATE events. In my experiments, we only succeed in connecting to ALSA after the last event. This means, we’ll have several CREATE events that we receive, remove the watcher, attempt to connect, fail, and then re-add the watcher. What if that “last” CREATE event occurs while our watcher has been removed? That’s right, we miss it, and will get stuck waiting forever. The solution is keep the watcher around. Now, if we’ve been successfully connected to ALSA for a long time, chances are we’ve built up events (for other cards, for example). We don’t want to trigger a storm of re-connect attempts, so drain the event queue after having been disconnected from ALSA. There *is* a small race here - if a card is removed and re-added *very* fast, we _may_ accidentally drain the CREATE event. I don’t see this happening in reality though. --- modules/alsa.c | 79 ++++++++++++++++++++++++++++++++++---------------- 1 file changed, 54 insertions(+), 25 deletions(-) diff --git a/modules/alsa.c b/modules/alsa.c index aa985b0..368b1ee 100644 --- a/modules/alsa.c +++ b/modules/alsa.c @@ -318,38 +318,64 @@ run(struct module *mod) { int ret = 1; - int wd = -1; - int ifd = inotify_init(); + int ifd = inotify_init1(IN_NONBLOCK | IN_CLOEXEC); if (ifd < 0) { LOG_ERRNO("failed to inotify"); return 1; } + int wd = inotify_add_watch(ifd, "/dev/snd", IN_CREATE); + if (wd < 0) { + LOG_ERRNO("failed to create inotify watcher for /dev/snd"); + close(ifd); + return 1; + } + while (true) { enum run_state state = run_while_online(mod); switch (state) { case RUN_DONE: ret = 0; - break; + goto out; case RUN_ERROR: ret = 1; - break; + goto out; case RUN_FAILED_CONNECT: + break; + case RUN_DISCONNECTED: + /* + * We’ve been connected - drain the watcher + * + * We don’t want old, un-releated events (for other + * soundcards, for example) to trigger a storm of + * re-connect attempts. + */ + while (true) { + uint8_t buf[1024]; + ssize_t amount = read(ifd, buf, sizeof(buf)); + if (amount < 0) { + if (errno == EAGAIN) + break; + + LOG_ERRNO("failed to drain inotify watcher"); + ret = 1; + goto out; + } + + if (amount == 0) + break; + } + break; } - wd = inotify_add_watch(ifd, "/dev/snd", IN_CREATE); - if (wd < 0) { - LOG_ERRNO("failed to create inotify watcher for /dev/snd"); - ret = 1; - break; - } + bool have_create_event = false; - while (true) { + while (!have_create_event) { struct pollfd fds[] = {{.fd = mod->abort_fd, .events = POLLIN}, {.fd = ifd, .events = POLLIN}}; int r = poll(fds, sizeof(fds) / sizeof(fds[0]), -1); @@ -363,42 +389,45 @@ run(struct module *mod) goto out; } - if (fds[0].revents & POLLIN) { + if (fds[0].revents & (POLLIN | POLLHUP)) { ret = 0; goto out; } - if (fds[1].revents & POLLIN) { + if (fds[1].revents & POLLHUP) { + LOG_ERR("inotify socket closed"); + ret = 1; + goto out; + } + + assert(fds[1].revents & POLLIN); + + while (true) { char buf[1024]; ssize_t len = read(ifd, buf, sizeof(buf)); if (len < 0) { + if (errno == EAGAIN) + break; + LOG_ERRNO("failed to read inotify events"); ret = 1; goto out; } - if (len == 0) { - LOG_ERR("inotify FD closed"); - ret = 1; - goto out; - } + if (len == 0) + break; /* Consume inotify data */ - bool have_create_event = false; for (const char *ptr = buf; ptr < buf + len; ) { const struct inotify_event *e = (const struct inotify_event *)ptr; + if (e->mask & IN_CREATE) { LOG_DBG("inotify: CREATED: /dev/snd/%.*s", e->len, e->name); have_create_event = true; } - ptr += sizeof(*e) + e->len; - } - if (have_create_event) { - inotify_rm_watch(ifd, wd); - wd = -1; - break; + ptr += sizeof(*e) + e->len; } } } From a5be5509645fcdd88eb08005ac900c82ff2d34d8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Daniel=20Ekl=C3=B6f?= Date: Sat, 21 Aug 2021 15:26:53 +0200 Subject: [PATCH 4/4] module/alsa: free channel list on each connect attempt MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Otherwise we’ll keep adding the same channel(s) over and over again, for each (successful) connect attempt. I.e. if you plug and unplug an USB soundcard repeatedly, we’ll keep extending the channel list each time. --- modules/alsa.c | 3 +++ 1 file changed, 3 insertions(+) diff --git a/modules/alsa.c b/modules/alsa.c index 368b1ee..d3f14e5 100644 --- a/modules/alsa.c +++ b/modules/alsa.c @@ -188,6 +188,9 @@ run_while_online(struct module *mod) struct private *m = mod->private; enum run_state ret = RUN_ERROR; + /* Make sure we aren’t still tracking channels from previous connects */ + tll_free(m->channels); + snd_mixer_t *handle; if (snd_mixer_open(&handle, 0) != 0) { LOG_ERR("failed to open handle");