@samitouri / QOSamiQemu / commits / da0625fc85

audio/alsa: replace custom logging with error_report and trace events

The ALSA audio backend uses its own logging infrastructure (AUD_log, AUD_vlog, dolog, ldebug) and a custom alsa_dump_info() debug helper. This approach is inconsistent with the rest of QEMU and makes the output harder to filter and configure. Replace the custom logging with standard QEMU error reporting: - Use error_report() / error_printf() for errors - Use warn_report() for non-fatal warnings (invalid formats, rejected parameters, unexpected states) - Convert ldebug() calls and alsa_dump_info() to trace events Remove DEBUG_ALSA and AUDIO_CAP macros which are no longer needed. Reviewed-by: Mark Cave-Ayland <mark.caveayland@nutanix.com> Reviewed-by: Akihiko Odaki <odaki@rsg.ci.i.u-tokyo.ac.jp> Signed-off-by: Marc-André Lureau <marcandre.lureau@redhat.com>

Marc-André Lureau committed Jan 20, 2026 at 17:40 UTC da0625fc85735a6c40eea5131c3356d21fbc3bfa
2 files changed +72 -102
audio/alsaaudio.c
+67 -102
@@ -26,17 +26,15 @@
26 #include <alsa/asoundlib.h>
27 #include "qemu/main-loop.h"
28 #include "qemu/module.h"
29 +#include "qemu/error-report.h"
30 #include "qemu/audio.h"
31 #include "qom/object.h"
32 #include "trace.h"
33
34 #pragma GCC diagnostic ignored "-Waddress"
35
35 -#define AUDIO_CAP "alsa"
36 #include "audio_int.h"
37
38 -#define DEBUG_ALSA 0
39 -
38 #define TYPE_AUDIO_ALSA "audio-alsa"
39 OBJECT_DECLARE_SIMPLE_TYPE(AudioALSA, AUDIO_ALSA)
40
@@ -81,33 +79,29 @@ struct alsa_params_obt {
79 snd_pcm_uframes_t samples;
80 };
81
84 -static void G_GNUC_PRINTF (2, 3) alsa_logerr (int err, const char *fmt, ...)
82 +static void G_GNUC_PRINTF(2, 3) alsa_logerr(int err, const char *fmt, ...)
83 {
84 va_list ap;
85
88 - va_start (ap, fmt);
89 - AUD_vlog (AUDIO_CAP, fmt, ap);
90 - va_end (ap);
91 -
92 - AUD_log (AUDIO_CAP, "Reason: %s\n", snd_strerror (err));
86 + error_printf("alsa: ");
87 + va_start(ap, fmt);
88 + error_vprintf(fmt, ap);
89 + va_end(ap);
90 + error_printf(" Reason: %s", snd_strerror(err));
91 + error_printf("\n");
92 }
93
95 -static void G_GNUC_PRINTF (3, 4) alsa_logerr2 (
96 - int err,
97 - const char *typ,
98 - const char *fmt,
99 - ...
100 - )
94 +static void G_GNUC_PRINTF(3, 4) alsa_logerr2(int err, const char *typ,
95 + const char *fmt, ...)
96 {
97 va_list ap;
98
104 - AUD_log (AUDIO_CAP, "Could not initialize %s\n", typ);
105 -
106 - va_start (ap, fmt);
107 - AUD_vlog (AUDIO_CAP, fmt, ap);
108 - va_end (ap);
109 -
110 - AUD_log (AUDIO_CAP, "Reason: %s\n", snd_strerror (err));
99 + error_printf("alsa: Could not initialize %s:", typ);
100 + va_start(ap, fmt);
101 + error_vprintf(fmt, ap);
102 + va_end(ap);
103 + error_printf(" Reason: %s", snd_strerror(err));
104 + error_printf("\n");
105 }
106
107 static void alsa_fini_poll (struct pollhlp *hlp)
@@ -130,7 +124,7 @@ static void alsa_anal_close1 (snd_pcm_t **handlep)
124 {
125 int err = snd_pcm_close (*handlep);
126 if (err) {
133 - alsa_logerr (err, "Failed to close PCM handle %p\n", *handlep);
127 + alsa_logerr(err, "Failed to close PCM handle %p", *handlep);
128 }
129 *handlep = NULL;
130 }
@@ -145,7 +139,7 @@ static int alsa_recover (snd_pcm_t *handle)
139 {
140 int err = snd_pcm_prepare (handle);
141 if (err < 0) {
148 - alsa_logerr (err, "Failed to prepare handle %p\n", handle);
142 + alsa_logerr(err, "Failed to prepare handle %p", handle);
143 return -1;
144 }
145 return 0;
@@ -155,7 +149,7 @@ static int alsa_resume (snd_pcm_t *handle)
149 {
150 int err = snd_pcm_resume (handle);
151 if (err < 0) {
158 - alsa_logerr (err, "Failed to resume handle %p\n", handle);
152 + alsa_logerr(err, "Failed to resume handle %p", handle);
153 return -1;
154 }
155 return 0;
@@ -170,7 +164,7 @@ static void alsa_poll_handler (void *opaque)
164
165 count = poll (hlp->pfds, hlp->count, 0);
166 if (count < 0) {
173 - dolog ("alsa_poll_handler: poll %s\n", strerror (errno));
167 + warn_report("alsa_poll_handler: poll %s", strerror(errno));
168 return;
169 }
170
@@ -183,7 +177,7 @@ static void alsa_poll_handler (void *opaque)
177 err = snd_pcm_poll_descriptors_revents (hlp->handle, hlp->pfds,
178 hlp->count, &revents);
179 if (err < 0) {
186 - alsa_logerr (err, "snd_pcm_poll_descriptors_revents");
180 + alsa_logerr(err, "snd_pcm_poll_descriptors_revents");
181 return;
182 }
183
@@ -215,7 +209,7 @@ static void alsa_poll_handler (void *opaque)
209 break;
210
211 default:
218 - dolog ("Unexpected state %d\n", state);
212 + warn_report("alsa: Unexpected state %d", state);
213 }
214 }
215
@@ -226,8 +220,8 @@ static int alsa_poll_helper (snd_pcm_t *handle, struct pollhlp *hlp, int mask)
220
221 count = snd_pcm_poll_descriptors_count (handle);
222 if (count <= 0) {
229 - dolog ("Could not initialize poll mode\n"
230 - "Invalid number of poll descriptors %d\n", count);
223 + warn_report("alsa: Could not initialize poll mode: "
224 + "Invalid number of poll descriptors %d", count);
225 return -1;
226 }
227
@@ -235,8 +229,7 @@ static int alsa_poll_helper (snd_pcm_t *handle, struct pollhlp *hlp, int mask)
229
230 err = snd_pcm_poll_descriptors (handle, pfds, count);
231 if (err < 0) {
238 - alsa_logerr (err, "Could not initialize poll mode\n"
239 - "Could not obtain poll descriptors\n");
232 + alsa_logerr(err, "Could not initialize poll mode: Could not obtain poll descriptors");
233 g_free (pfds);
234 return -1;
235 }
@@ -298,10 +291,7 @@ static snd_pcm_format_t aud_to_alsafmt(AudioFormat fmt, bool big_endian)
291 return big_endian ? SND_PCM_FORMAT_FLOAT_BE : SND_PCM_FORMAT_FLOAT_LE;
292
293 default:
301 - dolog ("Internal logic error: Bad audio format %d\n", fmt);
302 -#ifdef DEBUG_AUDIO
303 - abort ();
304 -#endif
294 + warn_report("alsa: Internal logic error: Bad audio format %d", fmt);
295 return SND_PCM_FORMAT_U8;
296 }
297 }
@@ -371,29 +361,13 @@ static int alsa_to_audfmt (snd_pcm_format_t alsafmt, AudioFormat *fmt,
361 break;
362
363 default:
374 - dolog ("Unrecognized audio format %d\n", alsafmt);
364 + warn_report("alsa: Unrecognized audio format %d", alsafmt);
365 return -1;
366 }
367
368 return 0;
369 }
370
381 -static void alsa_dump_info (struct alsa_params_req *req,
382 - struct alsa_params_obt *obt,
383 - snd_pcm_format_t obtfmt,
384 - AudiodevAlsaPerDirectionOptions *apdo)
385 -{
386 - dolog("parameter | requested value | obtained value\n");
387 - dolog("format | %10d | %10d\n", req->fmt, obtfmt);
388 - dolog("channels | %10d | %10d\n",
389 - req->nchannels, obt->nchannels);
390 - dolog("frequency | %10d | %10d\n", req->freq, obt->freq);
391 - dolog("============================================\n");
392 - dolog("requested: buffer len %" PRId32 " period len %" PRId32 "\n",
393 - apdo->buffer_length, apdo->period_length);
394 - dolog("obtained: samples %ld\n", obt->samples);
395 -}
396 -
371 static void alsa_set_threshold (snd_pcm_t *handle, snd_pcm_uframes_t threshold)
372 {
373 int err;
@@ -403,23 +377,22 @@ static void alsa_set_threshold (snd_pcm_t *handle, snd_pcm_uframes_t threshold)
377
378 err = snd_pcm_sw_params_current (handle, sw_params);
379 if (err < 0) {
406 - dolog ("Could not fully initialize DAC\n");
407 - alsa_logerr (err, "Failed to get current software parameters\n");
380 + error_report("alsa: Could not fully initialize DAC");
381 + alsa_logerr(err, "Failed to get current software parameters");
382 return;
383 }
384
385 err = snd_pcm_sw_params_set_start_threshold (handle, sw_params, threshold);
386 if (err < 0) {
413 - dolog ("Could not fully initialize DAC\n");
414 - alsa_logerr (err, "Failed to set software threshold to %ld\n",
415 - threshold);
387 + error_report("alsa: Could not fully initialize DAC");
388 + alsa_logerr(err, "Failed to set software threshold to %ld", threshold);
389 return;
390 }
391
392 err = snd_pcm_sw_params (handle, sw_params);
393 if (err < 0) {
421 - dolog ("Could not fully initialize DAC\n");
422 - alsa_logerr (err, "Failed to set software parameters\n");
394 + error_report("alsa: Could not fully initialize DAC");
395 + alsa_logerr(err, "Failed to set software parameters");
396 return;
397 }
398 }
@@ -451,13 +424,13 @@ static int alsa_open(bool in, struct alsa_params_req *req,
424 SND_PCM_NONBLOCK
425 );
426 if (err < 0) {
454 - alsa_logerr2 (err, typ, "Failed to open `%s':\n", pcm_name);
427 + alsa_logerr2(err, typ, "Failed to open `%s'", pcm_name);
428 return -1;
429 }
430
431 err = snd_pcm_hw_params_any (handle, hw_params);
432 if (err < 0) {
460 - alsa_logerr2 (err, typ, "Failed to initialize hardware parameters\n");
433 + alsa_logerr2(err, typ, "Failed to initialize hardware parameters");
434 goto err;
435 }
436
@@ -467,18 +440,18 @@ static int alsa_open(bool in, struct alsa_params_req *req,
440 SND_PCM_ACCESS_RW_INTERLEAVED
441 );
442 if (err < 0) {
470 - alsa_logerr2 (err, typ, "Failed to set access type\n");
443 + alsa_logerr2(err, typ, "Failed to set access type");
444 goto err;
445 }
446
447 err = snd_pcm_hw_params_set_format (handle, hw_params, req->fmt);
448 if (err < 0) {
476 - alsa_logerr2 (err, typ, "Failed to set format %d\n", req->fmt);
449 + alsa_logerr2(err, typ, "Failed to set format %d", req->fmt);
450 }
451
452 err = snd_pcm_hw_params_set_rate_near (handle, hw_params, &freq, 0);
453 if (err < 0) {
481 - alsa_logerr2 (err, typ, "Failed to set frequency %d\n", req->freq);
454 + alsa_logerr2(err, typ, "Failed to set frequency %d", req->freq);
455 goto err;
456 }
457
@@ -488,8 +461,7 @@ static int alsa_open(bool in, struct alsa_params_req *req,
461 &nchannels
462 );
463 if (err < 0) {
491 - alsa_logerr2 (err, typ, "Failed to set number of channels %d\n",
492 - req->nchannels);
464 + alsa_logerr2(err, typ, "Failed to set number of channels %d", req->nchannels);
465 goto err;
466 }
467
@@ -501,14 +473,14 @@ static int alsa_open(bool in, struct alsa_params_req *req,
473 handle, hw_params, &btime, &dir);
474
475 if (err < 0) {
504 - alsa_logerr2(err, typ, "Failed to set buffer time to %" PRId32 "\n",
476 + alsa_logerr2(err, typ, "Failed to set buffer time to %" PRId32,
477 apdo->buffer_length);
478 goto err;
479 }
480
481 if (apdo->has_buffer_length && btime != apdo->buffer_length) {
510 - dolog("Requested buffer time %" PRId32
511 - " was rejected, using %u\n", apdo->buffer_length, btime);
482 + warn_report("alsa: Requested buffer time %" PRId32 " was rejected, using %u",
483 + apdo->buffer_length, btime);
484 }
485 }
486
@@ -520,43 +492,43 @@ static int alsa_open(bool in, struct alsa_params_req *req,
492 &dir);
493
494 if (err < 0) {
523 - alsa_logerr2(err, typ, "Failed to set period time to %" PRId32 "\n",
495 + alsa_logerr2(err, typ, "Failed to set period time to %" PRId32,
496 apdo->period_length);
497 goto err;
498 }
499
500 if (apdo->has_period_length && ptime != apdo->period_length) {
529 - dolog("Requested period time %" PRId32 " was rejected, using %d\n",
530 - apdo->period_length, ptime);
501 + warn_report("alsa: Requested period time %" PRId32 " was rejected, using %d",
502 + apdo->period_length, ptime);
503 }
504 }
505
506 err = snd_pcm_hw_params (handle, hw_params);
507 if (err < 0) {
536 - alsa_logerr2 (err, typ, "Failed to apply audio parameters\n");
508 + alsa_logerr2(err, typ, "Failed to apply audio parameters");
509 goto err;
510 }
511
512 err = snd_pcm_hw_params_get_buffer_size (hw_params, &obt_buffer_size);
513 if (err < 0) {
542 - alsa_logerr2 (err, typ, "Failed to get buffer size\n");
514 + alsa_logerr2(err, typ, "Failed to get buffer size");
515 goto err;
516 }
517
518 err = snd_pcm_hw_params_get_format (hw_params, &obtfmt);
519 if (err < 0) {
548 - alsa_logerr2 (err, typ, "Failed to get format\n");
520 + alsa_logerr2(err, typ, "Failed to get format");
521 goto err;
522 }
523
524 if (alsa_to_audfmt (obtfmt, &obt->fmt, &obt->endianness)) {
553 - dolog ("Invalid format was returned %d\n", obtfmt);
525 + error_report("alsa: Invalid format was returned %d", obtfmt);
526 goto err;
527 }
528
529 err = snd_pcm_prepare (handle);
530 if (err < 0) {
559 - alsa_logerr2 (err, typ, "Could not prepare handle %p\n", handle);
531 + alsa_logerr2(err, typ, "Could not prepare handle %p", handle);
532 goto err;
533 }
534
@@ -574,11 +546,9 @@ static int alsa_open(bool in, struct alsa_params_req *req,
546
547 *handlep = handle;
548
577 - if (DEBUG_ALSA || obtfmt != req->fmt ||
578 - obt->nchannels != req->nchannels || obt->freq != req->freq) {
579 - dolog ("Audio parameters for %s\n", typ);
580 - alsa_dump_info(req, obt, obtfmt, apdo);
581 - }
549 + trace_alsa_info_params(req->fmt, obtfmt, req->nchannels, obt->nchannels,
550 + req->freq, obt->freq);
551 + trace_alsa_info_samples(apdo->buffer_length, apdo->period_length, obt->samples);
552
553 return 0;
554
@@ -601,8 +571,7 @@ static size_t alsa_buffer_get_free(HWVoiceOut *hw)
571 }
572 }
573 if (avail < 0) {
604 - alsa_logerr(avail,
605 - "Could not obtain number of available frames\n");
574 + alsa_logerr(avail, "Could not obtain number of available frames");
575 avail = 0;
576 }
577 }
@@ -643,8 +612,7 @@ static size_t alsa_write(HWVoiceOut *hw, void *buf, size_t len)
612
613 case -EPIPE:
614 if (alsa_recover(alsa->handle)) {
646 - alsa_logerr(written, "Failed to write %zu frames\n",
647 - len_frames);
615 + alsa_logerr(written, "Failed to write %zu frames", len_frames);
616 return pos;
617 }
618 trace_alsa_xrun_out();
@@ -656,8 +624,7 @@ static size_t alsa_write(HWVoiceOut *hw, void *buf, size_t len)
624 * recovery
625 */
626 if (alsa_resume(alsa->handle)) {
659 - alsa_logerr(written, "Failed to write %zu frames\n",
660 - len_frames);
627 + alsa_logerr(written, "Failed to write %zu frames", len_frames);
628 return pos;
629 }
630 trace_alsa_resume_out();
@@ -667,8 +634,7 @@ static size_t alsa_write(HWVoiceOut *hw, void *buf, size_t len)
634 return pos;
635
636 default:
670 - alsa_logerr(written, "Failed to write %zu frames from %p\n",
671 - len, src);
637 + alsa_logerr(written, "Failed to write %zu frames from %p", len_frames, src);
638 return pos;
639 }
640 }
@@ -687,7 +653,7 @@ static void alsa_fini_out (HWVoiceOut *hw)
653 {
654 ALSAVoiceOut *alsa = (ALSAVoiceOut *) hw;
655
690 - ldebug ("alsa_fini\n");
656 + trace_alsa_fini_out();
657 alsa_anal_close (&alsa->handle, &alsa->pollhlp);
658 }
659
@@ -732,19 +698,19 @@ static int alsa_voice_ctl (snd_pcm_t *handle, const char *typ, int ctl)
698 if (ctl == VOICE_CTL_PAUSE) {
699 err = snd_pcm_drop (handle);
700 if (err < 0) {
735 - alsa_logerr (err, "Could not stop %s\n", typ);
701 + alsa_logerr(err, "Could not stop %s", typ);
702 return -1;
703 }
704 } else {
705 err = snd_pcm_prepare (handle);
706 if (err < 0) {
741 - alsa_logerr (err, "Could not prepare handle for %s\n", typ);
707 + alsa_logerr(err, "Could not prepare handle for %s", typ);
708 return -1;
709 }
710 if (ctl == VOICE_CTL_START) {
711 err = snd_pcm_start(handle);
712 if (err < 0) {
747 - alsa_logerr (err, "Could not start handle for %s\n", typ);
713 + alsa_logerr(err, "Could not start handle for %s", typ);
714 return -1;
715 }
716 }
@@ -758,17 +724,17 @@ static void alsa_enable_out(HWVoiceOut *hw, bool enable)
724 ALSAVoiceOut *alsa = (ALSAVoiceOut *) hw;
725 AudiodevAlsaPerDirectionOptions *apdo = hw->s->dev->u.alsa.out;
726
727 + trace_alsa_enable_out(enable);
728 +
729 if (enable) {
730 bool poll_mode = apdo->try_poll;
731
764 - ldebug("enabling voice\n");
732 if (poll_mode && alsa_poll_out(hw)) {
733 poll_mode = 0;
734 }
735 hw->poll_mode = poll_mode;
736 alsa_voice_ctl(alsa->handle, "playback", VOICE_CTL_PREPARE);
737 } else {
771 - ldebug("disabling voice\n");
738 if (hw->poll_mode) {
739 hw->poll_mode = 0;
740 alsa_fini_poll(&alsa->pollhlp);
@@ -834,7 +800,7 @@ static size_t alsa_read(HWVoiceIn *hw, void *buf, size_t len)
800
801 case -EPIPE:
802 if (alsa_recover(alsa->handle)) {
837 - alsa_logerr(nread, "Failed to read %zu frames\n", len);
803 + alsa_logerr(nread, "Failed to read %zu frames", len);
804 return pos;
805 }
806 trace_alsa_xrun_in();
@@ -844,8 +810,7 @@ static size_t alsa_read(HWVoiceIn *hw, void *buf, size_t len)
810 return pos;
811
812 default:
847 - alsa_logerr(nread, "Failed to read %zu frames to %p\n",
848 - len, dst);
813 + alsa_logerr(nread, "Failed to read %zu frames to %p", len, dst);
814 return pos;
815 }
816 }
@@ -862,10 +827,11 @@ static void alsa_enable_in(HWVoiceIn *hw, bool enable)
827 ALSAVoiceIn *alsa = (ALSAVoiceIn *) hw;
828 AudiodevAlsaPerDirectionOptions *apdo = hw->s->dev->u.alsa.in;
829
830 + trace_alsa_enable_in(enable);
831 +
832 if (enable) {
833 bool poll_mode = apdo->try_poll;
834
868 - ldebug("enabling voice\n");
835 if (poll_mode && alsa_poll_in(hw)) {
836 poll_mode = 0;
837 }
@@ -873,7 +839,6 @@ static void alsa_enable_in(HWVoiceIn *hw, bool enable)
839
840 alsa_voice_ctl(alsa->handle, "capture", VOICE_CTL_START);
841 } else {
876 - ldebug ("disabling voice\n");
842 if (hw->poll_mode) {
843 hw->poll_mode = 0;
844 alsa_fini_poll(&alsa->pollhlp);
audio/trace-events
+5
@@ -9,6 +9,11 @@ alsa_read_zero(long len) "Failed to read %ld frames (read zero)"
9 alsa_xrun_out(void) "Recovering from playback xrun"
10 alsa_xrun_in(void) "Recovering from capture xrun"
11 alsa_resume_out(void) "Resuming suspended output stream"
12 +alsa_info_params(int req_fmt, int obt_fmt, int req_channels, int obt_channels, int req_freq, int obt_freq) "format %d->%d, channels %d->%d, frequency %d->%d"
13 +alsa_info_samples(int buffer_length, int period_length, long samples) "requested: buffer len %d, period len %d; obtained: %ld samples"
14 +alsa_fini_out(void) ""
15 +alsa_enable_out(bool enable) "enable=%d"
16 +alsa_enable_in(bool enable) "enable=%d"
17
18 # ossaudio.c
19 oss_version(int version) "OSS version = 0x%x"