diff options
author | Marcus Müller <mmueller@gnuradio.org> | 2020-04-11 00:46:24 +0200 |
---|---|---|
committer | Marcus Müller <marcus@hostalia.de> | 2020-04-13 15:55:41 +0200 |
commit | 337b99e78fddb4589ebbc793d7f4784daa4314d8 (patch) | |
tree | 1f0003755f7a13056ce2600475298a4dbcaa6ef0 | |
parent | 0f88db1ef0569bf6fcd5e9c843da38d487a6f54b (diff) |
audio: replace stderr logging by calls to GR's logging facilties
This is a bit special, in that audio systems tend to have their own ways
of going wrong, and there's platform-specific development debugging
infrastructure in there, which I intentionally did not touch.
I did touch a few commented lines of code in the intention of, if you
enable that line of logging, it should be consistent with the rest.
There's copious amounts of untouched stderr-logging in `#if 0`-disabled
code in OSX's infrastructure.
-rw-r--r-- | gr-audio/lib/alsa/alsa_impl.cc | 23 | ||||
-rw-r--r-- | gr-audio/lib/alsa/alsa_sink.cc | 13 | ||||
-rw-r--r-- | gr-audio/lib/audio_registry.cc | 16 | ||||
-rw-r--r-- | gr-audio/lib/oss/oss_sink.cc | 30 | ||||
-rw-r--r-- | gr-audio/lib/oss/oss_source.cc | 31 | ||||
-rw-r--r-- | gr-audio/lib/osx/circular_buffer.h | 73 | ||||
-rw-r--r-- | gr-audio/lib/osx/osx_impl.cc | 20 | ||||
-rw-r--r-- | gr-audio/lib/osx/osx_sink.cc | 189 | ||||
-rw-r--r-- | gr-audio/lib/portaudio/portaudio_sink.cc | 99 | ||||
-rw-r--r-- | gr-audio/lib/portaudio/portaudio_sink.h | 4 | ||||
-rw-r--r-- | gr-audio/lib/portaudio/portaudio_source.cc | 75 | ||||
-rw-r--r-- | gr-audio/lib/portaudio/portaudio_source.h | 1 | ||||
-rw-r--r-- | gr-audio/lib/windows/windows_sink.cc | 90 | ||||
-rw-r--r-- | gr-audio/lib/windows/windows_sink.h | 1 | ||||
-rw-r--r-- | gr-audio/lib/windows/windows_source.cc | 57 |
15 files changed, 405 insertions, 317 deletions
diff --git a/gr-audio/lib/alsa/alsa_impl.cc b/gr-audio/lib/alsa/alsa_impl.cc index d5b8214ecc..67b608aa7e 100644 --- a/gr-audio/lib/alsa/alsa_impl.cc +++ b/gr-audio/lib/alsa/alsa_impl.cc @@ -9,9 +9,12 @@ */ #ifdef HAVE_CONFIG_H +#warning "ALSA CONFIG H" #include "config.h" #endif +#include <gnuradio/logger.h> + #include "alsa_impl.h" #include <algorithm> @@ -138,22 +141,23 @@ bool gri_alsa_pick_acceptable_format(snd_pcm_t* pcm, bool verbose) { int err; + gr::logger_ptr logger, debug_logger; + gr::configure_default_loggers( + logger, debug_logger, "gri_alsa_pick_acceptable_format"); // pick a format that we like... for (unsigned i = 0; i < nacceptable_formats; i++) { if (snd_pcm_hw_params_test_format(pcm, hwparams, acceptable_formats[i]) == 0) { err = snd_pcm_hw_params_set_format(pcm, hwparams, acceptable_formats[i]); if (err < 0) { - fprintf(stderr, - "%s[%s]: failed to set format: %s\n", - error_msg_tag, - snd_pcm_name(pcm), - snd_strerror(err)); + GR_LOG_ERROR(logger, + boost::format("%s[%s]: failed to set format: %s") % + error_msg_tag % snd_pcm_name(pcm) % snd_strerror(err)); return false; } if (verbose) fprintf(stdout, - "%s[%s]: using %s\n", + "%s[%s]: using %s", error_msg_tag, snd_pcm_name(pcm), snd_pcm_format_name(acceptable_formats[i])); @@ -162,9 +166,8 @@ bool gri_alsa_pick_acceptable_format(snd_pcm_t* pcm, } } - fprintf(stderr, - "%s[%s]: failed to find acceptable format", - error_msg_tag, - snd_pcm_name(pcm)); + GR_LOG_ERROR(logger, + boost::format("%s[%s]: failed to find acceptable format") % + error_msg_tag % snd_pcm_name(pcm)); return false; } diff --git a/gr-audio/lib/alsa/alsa_sink.cc b/gr-audio/lib/alsa/alsa_sink.cc index c573320857..f4e1cefb9e 100644 --- a/gr-audio/lib/alsa/alsa_sink.cc +++ b/gr-audio/lib/alsa/alsa_sink.cc @@ -17,7 +17,8 @@ #include "alsa_sink.h" #include <gnuradio/io_signature.h> #include <gnuradio/prefs.h> -#include <stdio.h> +#include <cstdio> +#include <future> #include <iostream> #include <stdexcept> @@ -257,7 +258,7 @@ bool alsa_sink::check_topology(int ninputs, int noutputs) d_buffer = new char[d_buffer_size_bytes]; if (CHATTY_DEBUG) { - GR_LOG_DEBUG(d_logger, + GR_LOG_DEBUG(d_debug_logger, boost::format("[%1%]: sample resolution = %2% bits") % snd_pcm_name(d_pcm_handle) % snd_pcm_hw_params_get_sbits(d_hw_params)); @@ -473,11 +474,11 @@ bool alsa_sink::write_buffer(const void* vbuffer, unsigned nframes, unsigned siz if (d_ok_to_block == true) continue; // try again break; - } - - else if (r == -EPIPE) { // underrun + } else if (r == -EPIPE) { // underrun d_nunderuns++; - fputs("aU", stderr); + // we need to have an lvalue, async pitfall! + auto future_local = std::async(::fputs, "aU", stderr); + if ((r = snd_pcm_prepare(d_pcm_handle)) < 0) { output_error_msg("snd_pcm_prepare failed. Can't recover from underrun", r); diff --git a/gr-audio/lib/audio_registry.cc b/gr-audio/lib/audio_registry.cc index 13ad989c61..5ca9c264f0 100644 --- a/gr-audio/lib/audio_registry.cc +++ b/gr-audio/lib/audio_registry.cc @@ -132,16 +132,20 @@ static void do_arch_warning(const std::string& arch) { if (arch == "auto") return; // no warning when arch not specified - std::cerr << "Could not find audio architecture \"" << arch << "\" in registry." - << std::endl; - std::cerr << " Defaulting to the first available architecture..." << std::endl; + + gr::logger_ptr logger, debug_logger; + gr::configure_default_loggers(logger, debug_logger, "audio_registry"); + std::ostringstream msg; + msg << "Could not find audio architecture \"" << arch << "\" in registry."; + msg << " Defaulting to the first available architecture."; + GR_LOG_ERROR(logger, msg.str()); } source::sptr source::make(int sampling_rate, const std::string device_name, bool ok_to_block) { gr::logger_ptr logger, debug_logger; - configure_default_loggers(logger, debug_logger, "audio source"); + configure_default_loggers(logger, debug_logger, "audio_source"); if (get_source_registry().empty()) { throw std::runtime_error("no available audio source factories"); @@ -158,7 +162,7 @@ source::make(int sampling_rate, const std::string device_name, bool ok_to_block) return e.source(sampling_rate, device_name, ok_to_block); } - GR_LOG_INFO(logger, boost::format("Audio source arch: %1%") % (entry.arch)); + GR_LOG_INFO(debug_logger, boost::format("Audio source arch: %1%") % (entry.arch)); return entry.source(sampling_rate, device_name, ok_to_block); } @@ -183,7 +187,7 @@ sink::sptr sink::make(int sampling_rate, const std::string device_name, bool ok_ } do_arch_warning(arch); - GR_LOG_INFO(logger, boost::format("Audio sink arch: %1%") % (entry.arch)); + GR_LOG_INFO(debug_logger, boost::format("Audio sink arch: %1%") % (entry.arch)); return entry.sink(sampling_rate, device_name, ok_to_block); } diff --git a/gr-audio/lib/oss/oss_sink.cc b/gr-audio/lib/oss/oss_sink.cc index 7033f16cfa..3a065b4e53 100644 --- a/gr-audio/lib/oss/oss_sink.cc +++ b/gr-audio/lib/oss/oss_sink.cc @@ -52,8 +52,9 @@ oss_sink::oss_sink(int sampling_rate, const std::string device_name, bool ok_to_ d_chunk_size(0) { if ((d_fd = open(d_device_name.c_str(), O_WRONLY)) < 0) { - fprintf(stderr, "audio_oss_sink: "); - perror(d_device_name.c_str()); + GR_LOG_ERROR(d_logger, + boost::format("opening device %s: %s") % d_device_name % + strerror(errno)); throw std::runtime_error("audio_oss_sink"); } @@ -68,31 +69,36 @@ oss_sink::oss_sink(int sampling_rate, const std::string device_name, bool ok_to_ int format = AFMT_S16_NE; int orig_format = format; if (ioctl(d_fd, SNDCTL_DSP_SETFMT, &format) < 0) { - std::cerr << "audio_oss_sink: " << d_device_name << " ioctl failed\n"; - perror(d_device_name.c_str()); + GR_LOG_ERROR(d_logger, + boost::format("%s ioctl failed: %s") % d_device_name % + strerror(errno)); throw std::runtime_error("audio_oss_sink"); } if (format != orig_format) { - fprintf(stderr, "audio_oss_sink: unable to support format %d\n", orig_format); - fprintf(stderr, " card requested %d instead.\n", format); + GR_LOG_ERROR( + d_logger, + boost::format("%s unable to support format %d. card requested %d instead.") % + orig_format % format); } // set to stereo no matter what. Some hardware only does stereo int channels = 2; if (ioctl(d_fd, SNDCTL_DSP_CHANNELS, &channels) < 0 || channels != 2) { - perror("audio_oss_sink: could not set STEREO mode"); + GR_LOG_ERROR(d_logger, + boost::format("could not set STEREO mode: %s") % strerror(errno)); throw std::runtime_error("audio_oss_sink"); } // set sampling freq int sf = sampling_rate; if (ioctl(d_fd, SNDCTL_DSP_SPEED, &sf) < 0) { - std::cerr << "audio_oss_sink: " << d_device_name << ": invalid sampling_rate " - << sampling_rate << "\n"; + GR_LOG_ERROR(d_logger, + boost::format("%s: invalid sampling_rate %d") % d_device_name % + sampling_rate); sampling_rate = 8000; if (ioctl(d_fd, SNDCTL_DSP_SPEED, &sf) < 0) { - std::cerr << "audio_oss_sink: failed to set sampling_rate to 8000\n"; + GR_LOG_ERROR(d_logger, "failed to set sampling_rate to 8000"); throw std::runtime_error("audio_oss_sink"); } } @@ -121,7 +127,7 @@ int oss_sink::work(int noutput_items, } f0 += d_chunk_size; if (write(d_fd, d_buffer, 2 * d_chunk_size * sizeof(short)) < 0) - perror("audio_oss_sink: write"); + GR_LOG_ERROR(d_logger, boost::format("write %s") % strerror(errno)); } break; @@ -137,7 +143,7 @@ int oss_sink::work(int noutput_items, f0 += d_chunk_size; f1 += d_chunk_size; if (write(d_fd, d_buffer, 2 * d_chunk_size * sizeof(short)) < 0) - perror("audio_oss_sink: write"); + GR_LOG_ERROR(d_logger, boost::format("write %s") % strerror(errno)); } break; } diff --git a/gr-audio/lib/oss/oss_source.cc b/gr-audio/lib/oss/oss_source.cc index 2792d70a99..0ac46007b2 100644 --- a/gr-audio/lib/oss/oss_source.cc +++ b/gr-audio/lib/oss/oss_source.cc @@ -52,8 +52,9 @@ oss_source::oss_source(int sampling_rate, const std::string device_name, bool ok d_chunk_size(0) { if ((d_fd = open(d_device_name.c_str(), O_RDONLY)) < 0) { - fprintf(stderr, "audio_oss_source: "); - perror(d_device_name.c_str()); + GR_LOG_ERROR(d_logger, + boost::format("opening device %s: %s") % d_device_name % + strerror(errno)); throw std::runtime_error("audio_oss_source"); } @@ -68,31 +69,36 @@ oss_source::oss_source(int sampling_rate, const std::string device_name, bool ok int format = AFMT_S16_NE; int orig_format = format; if (ioctl(d_fd, SNDCTL_DSP_SETFMT, &format) < 0) { - std::cerr << "audio_oss_source: " << d_device_name << " ioctl failed\n"; - perror(d_device_name.c_str()); + GR_LOG_ERROR(d_logger, + boost::format("%s ioctl failed %s") % d_device_name % + strerror(errno)); throw std::runtime_error("audio_oss_source"); } if (format != orig_format) { - fprintf(stderr, "audio_oss_source: unable to support format %d\n", orig_format); - fprintf(stderr, " card requested %d instead.\n", format); + GR_LOG_ERROR( + d_logger, + boost::format("%s unable to support format %d. card requested %d instead.") % + orig_format % format); } // set to stereo no matter what. Some hardware only does stereo int channels = 2; if (ioctl(d_fd, SNDCTL_DSP_CHANNELS, &channels) < 0 || channels != 2) { - perror("audio_oss_source: could not set STEREO mode"); + GR_LOG_ERROR(d_logger, + boost::format("could not set STEREO mode: %s") % strerror(errno)); throw std::runtime_error("audio_oss_source"); } // set sampling freq int sf = sampling_rate; if (ioctl(d_fd, SNDCTL_DSP_SPEED, &sf) < 0) { - std::cerr << "audio_oss_source: " << d_device_name << ": invalid sampling_rate " - << sampling_rate << "\n"; + GR_LOG_ERROR(d_logger, + boost::format("ERROR %s: invalid sampling_rate %d") % d_device_name % + sampling_rate); sampling_rate = 8000; if (ioctl(d_fd, SNDCTL_DSP_SPEED, &sf) < 0) { - std::cerr << "audio_oss_source: failed to set sampling_rate to 8000\n"; + GR_LOG_ERROR(d_logger, "failed to set sampling_rate to 8000"); throw std::runtime_error("audio_oss_source"); } } @@ -127,12 +133,13 @@ int oss_source::work(int noutput_items, int result_nbytes = read(d_fd, d_buffer, nbytes); if (result_nbytes < 0) { - perror("audio_oss_source"); + GR_LOG_ERROR(d_logger, + boost::format("audio_oss_source: %s") % strerror(errno)); return -1; // say we're done } if ((result_nbytes & (bytes_per_item - 1)) != 0) { - fprintf(stderr, "audio_oss_source: internal error.\n"); + GR_LOG_ERROR(d_logger, "internal error."); throw std::runtime_error("internal error"); } diff --git a/gr-audio/lib/osx/circular_buffer.h b/gr-audio/lib/osx/circular_buffer.h index 4a19e3ac6c..6d48de5edf 100644 --- a/gr-audio/lib/osx/circular_buffer.h +++ b/gr-audio/lib/osx/circular_buffer.h @@ -11,6 +11,7 @@ #ifndef _CIRCULAR_BUFFER_H_ #define _CIRCULAR_BUFFER_H_ +#include <gnuradio/logger.h> #include <gnuradio/thread/thread.h> #include <iostream> #include <stdexcept> @@ -20,13 +21,13 @@ #endif #if DO_DEBUG -#define DEBUG(X) \ - do { \ - X \ +#define LOG(X) \ + do { \ + X \ } while (0); #else -#define DEBUG(X) \ - do { \ +#define LOG(X) \ + do { \ } while (0); #endif @@ -66,6 +67,8 @@ private: }; public: + gr::logger_ptr d_logger, d_debug_logger; + circular_buffer(size_t bufLen_I, bool doWriteBlock = true, bool doFullRead = false) { if (bufLen_I == 0) @@ -78,10 +81,12 @@ public: d_internal = NULL; d_readBlock = d_writeBlock = NULL; reset(); - DEBUG(std::cerr << "c_b(): buf len (items) = " << d_bufLen_ - << ", doWriteBlock = " << (d_doWriteBlock ? "true" : "false") - << ", doFullRead = " << (d_doFullRead ? "true" : "false") - << std::endl); + gr::configure_default_loggers(d_logger, d_debug_logger, "circular_buffer"); + LOG(std::ostringstream msg; + msg << "c_b(): buf len (items) = " << d_bufLen_ + << ", doWriteBlock = " << (d_doWriteBlock ? "true" : "false") + << ", doFullRead = " << (d_doFullRead ? "true" : "false"); + GR_LOG_INFO(d_debug_logger, msg.str());); }; ~circular_buffer() @@ -150,13 +155,16 @@ public: int enqueue(T* buf, size_t bufLen_I) { - DEBUG(std::cerr << "enqueue: buf = " << (void*)buf << ", bufLen = " << bufLen_I - << ", #av_wr = " << d_n_avail_write_I - << ", #av_rd = " << d_n_avail_read_I << std::endl); + LOG(std::ostringstream msg; + msg << "enqueue: buf = " << (void*)buf << ", bufLen = " << bufLen_I + << ", #av_wr = " << d_n_avail_write_I + << ", #av_rd = " << d_n_avail_read_I; + GR_LOG_INFO(d_debug_logger, msg.str());); if (bufLen_I > d_bufLen_I) { - std::cerr << "ERROR: cannot add buffer longer (" << bufLen_I - << ") than instantiated length (" << d_bufLen_I << ")." - << std::endl; + std::ostringstream msg; + msg << "cannot add buffer longer (" << bufLen_I + << ") than instantiated length (" << d_bufLen_I << ")."; + GR_LOG_INFO(d_debug_logger, msg.str()); throw std::runtime_error("circular_buffer::enqueue()"); } @@ -174,21 +182,21 @@ public: if (bufLen_I > d_n_avail_write_I) { if (d_doWriteBlock) { while (bufLen_I > d_n_avail_write_I) { - DEBUG(std::cerr << "enqueue: #len > #a, waiting." << std::endl); + LOG(GR_LOG_INFO(d_debug_logger, "enqueue #len > #a, waiting");); // wait; will automatically unlock() the internal mutex via // the scoped lock d_writeBlock->wait(l); // and auto re-lock() it here. if (d_doAbort) { - DEBUG(std::cerr << "enqueue: #len > #a, aborting." << std::endl); + LOG(GR_LOG_INFO(d_debug_logger, "enqueue #len > #a, aborting");); return (2); } - DEBUG(std::cerr << "enqueue: #len > #a, done waiting." << std::endl); + LOG(GR_LOG_INFO(d_debug_logger, "enqueue #len > #a, done waiting");); } } else { d_n_avail_read_I = d_bufLen_I - bufLen_I; d_n_avail_write_I = bufLen_I; - DEBUG(std::cerr << "circular_buffer::enqueue: overflow" << std::endl); + LOG(GR_LOG_ERROR(d_logger, "enqueue overflow");); retval = -1; } } @@ -236,9 +244,11 @@ public: int dequeue(T* buf, size_t* bufLen_I) { - DEBUG(std::cerr << "dequeue: buf = " << ((void*)buf) << ", *bufLen = " - << (*bufLen_I) << ", #av_wr = " << d_n_avail_write_I - << ", #av_rd = " << d_n_avail_read_I << std::endl); + LOG(std::ostringstream msg; + msg << "dequeue: buf = " << ((void*)buf) << ", *bufLen = " << (*bufLen_I) + << ", #av_wr = " << d_n_avail_write_I + << ", #av_rd = " << d_n_avail_read_I; + GR_LOG_INFO(d_debug_logger, msg.str());); if (!bufLen_I) throw std::runtime_error("circular_buffer::dequeue(): " "input bufLen pointer is NULL."); @@ -249,9 +259,10 @@ public: if (l_bufLen_I == 0) return (0); if (l_bufLen_I > d_bufLen_I) { - std::cerr << "ERROR: cannot remove buffer longer (" << l_bufLen_I - << ") than instantiated length (" << d_bufLen_I << ")." - << std::endl; + std::ostringstream msg; + msg << "cannot remove buffer longer (" << l_bufLen_I + << ") than instantiated length (" << d_bufLen_I << ")."; + GR_LOG_ERROR(d_logger, msg.str()); throw std::runtime_error("circular_buffer::dequeue()"); } @@ -261,29 +272,29 @@ public: } if (d_doFullRead) { while (d_n_avail_read_I < l_bufLen_I) { - DEBUG(std::cerr << "dequeue: #a < #len, waiting." << std::endl); + LOG(GR_LOG_INFO(d_debug_logger, "dequeue #a < #len, waiting");); // wait; will automatically unlock() the internal mutex via // the scoped lock d_readBlock->wait(l); // and re-lock() it here. if (d_doAbort) { - DEBUG(std::cerr << "dequeue: #a < #len, aborting." << std::endl); + LOG(GR_LOG_INFO(d_debug_logger, "dequeue #a < #len, aborting");); return (2); } - DEBUG(std::cerr << "dequeue: #a < #len, done waiting." << std::endl); + LOG(GR_LOG_INFO(d_debug_logger, "dequeue #a < #len, done waiting");); } } else { while (d_n_avail_read_I == 0) { - DEBUG(std::cerr << "dequeue: #a == 0, waiting." << std::endl); + LOG(GR_LOG_INFO(d_debug_logger, "dequeue: #a == 0, waiting.");); // wait; will automatically unlock() the internal mutex via // the scoped lock d_readBlock->wait(l); // and re-lock() it here. if (d_doAbort) { - DEBUG(std::cerr << "dequeue: #a == 0, aborting." << std::endl); + LOG(GR_LOG_INFO(d_debug_logger, "dequeue: #a == 0, aborting.");); return (2); } - DEBUG(std::cerr << "dequeue: #a == 0, done waiting." << std::endl); + LOG(GR_LOG_INFO(d_debug_logger, "dequeue: #a == 0, done waiting.");); } } if (l_bufLen_I > d_n_avail_read_I) diff --git a/gr-audio/lib/osx/osx_impl.cc b/gr-audio/lib/osx/osx_impl.cc index 2b1df1ee8f..15329f012f 100644 --- a/gr-audio/lib/osx/osx_impl.cc +++ b/gr-audio/lib/osx/osx_impl.cc @@ -15,6 +15,7 @@ #include "../audio_registry.h" #include <gnuradio/audio/osx_impl.h> +#include <gnuradio/logger.h> #include <algorithm> #include <iostream> @@ -151,8 +152,12 @@ void find_audio_devices(const std::string& device_name, if ((err = AudioObjectGetPropertyDataSize( kAudioObjectSystemObject, &ao_address, 0, NULL, &prop_size)) != noErr) { #if _OSX_AU_DEBUG_ - std::cerr << "audio_osx::find_audio_devices: " - << "Unable to retrieve number of audio objects: " << err << std::endl; + gr::logger_ptr logger, debug_logger; + gr::configure_default_loggers( + logger, debug_logger, "osx_impl::find_audio_devices"); + std::ostringstream msg; + msg << "Unable to retrieve number of audio objects: " << err; + GR_LOG_ERROR(logger, msg.str()); #endif return; } @@ -172,8 +177,9 @@ void find_audio_devices(const std::string& device_name, &prop_size, all_dev_ids.get())) != noErr) { #if _OSX_AU_DEBUG_ - std::cerr << "audio_osx::find_audio_devices: " - << "Unable to retrieve audio object ids: " << err << std::endl; + std::ostringstream msg; + msg << "Unable to retrieve audio object ids: " << err; + GR_LOG_ERROR(logger, msg.str()); #endif return; } @@ -227,9 +233,9 @@ void find_audio_devices(const std::string& device_name, if ((err = AudioObjectGetPropertyData( t_id, &ao_address, 0, NULL, &prop_size, (void*)c_name_buf)) != noErr) { #if _OSX_AU_DEBUG_ - std::cerr << "audio_osx::find_audio_devices: " - << "Unable to retrieve audio device name #" << (nn + 1) << ": " - << err << std::endl; + std::ostringstream msg; + msg << "Unable to retrieve audio device name #" << (nn + 1) << ": " << err; + GR_LOG_ERROR(logger, msg.str()); #endif continue; } diff --git a/gr-audio/lib/osx/osx_sink.cc b/gr-audio/lib/osx/osx_sink.cc index ef0da038db..2a0fa66934 100644 --- a/gr-audio/lib/osx/osx_sink.cc +++ b/gr-audio/lib/osx/osx_sink.cc @@ -16,6 +16,7 @@ #include "osx_sink.h" #include <gnuradio/io_signature.h> +#include <gnuradio/logger.h> #include <gnuradio/prefs.h> #include <stdexcept> @@ -88,7 +89,7 @@ void osx_sink::setup() if (all_names[0].compare(d_desired_name) != 0) { // yes: log the full device name - GR_LOG_INFO(d_logger, + GR_LOG_INFO(d_debug_logger, boost::format("Using output audio device '%s'.") % all_names[0]); } @@ -105,15 +106,18 @@ void osx_sink::setup() osx::find_audio_devices("", false, NULL, &all_names); - std::string err_str("\n\nA unique output audio device name " + std::string err_str("A unique output audio device name " "matching the string '"); err_str += d_desired_name; - err_str += "' was not found.\n\n"; + err_str += "' was not found."; err_str += "The current known output audio device name"; err_str += ((all_names.size() > 1) ? "s are" : " is"); - err_str += ":\n"; + err_str += ": "; for (UInt32 nn = 0; nn < all_names.size(); ++nn) { - err_str += " " + all_names[nn] + "\n"; + err_str += all_names[nn]; + if (nn != all_names - 1) { + err_str += ", "; + } } GR_LOG_ERROR(d_logger, boost::format(err_str)); throw std::runtime_error("audio_osx_sink::setup"); @@ -161,14 +165,13 @@ void osx_sink::setup() } else { - GR_LOG_INFO(d_logger, - boost::format("\n\nUsing output audio device '%s'.\n ... " - "which is the current default output audio" - " device.\n Changing the default output" - " audio device in the System Preferences" - " will \n result in changing it here, too " - "(with an internal reconfiguration).\n") % - std::string(c_name_buf)); + GR_LOG_INFO( + d_debug_logger, + boost::format( + "Using current default output audio device '%s'. Changing the " + "default audio device in the System Preferences will result in " + "changing it here, too (with an internal reconfiguration).") % + std::string(c_name_buf)); } d_selected_name = c_name_buf; @@ -198,9 +201,10 @@ void osx_sink::setup() (d_input_sample_rate < 50000.0 ? 50000 : (UInt32)d_input_sample_rate); #if _OSX_AU_DEBUG_ - std::cerr << ((void*)(pthread_self())) - << " : audio_osx_sink: max # samples = " << d_buffer_size_samples - << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) + << " : audio_osx_sink: max # samples = " << d_buffer_size_samples; + GR_LOG_INFO(d_debug_logger, msg.str()); #endif // create the default AudioUnit for output: @@ -223,7 +227,7 @@ void osx_sink::setup() AudioComponent comp = AudioComponentFindNext(NULL, &desc); if (!comp) { - GR_LOG_FATAL(d_logger, boost::format("AudioComponentFindNext Failed")); + GR_LOG_FATAL(d_logger, "AudioComponentFindNext Failed"); throw std::runtime_error("audio_osx_sink::setup"); } err = AudioComponentInstanceNew(comp, &d_output_au); @@ -234,7 +238,7 @@ void osx_sink::setup() Component comp = FindNextComponent(NULL, &desc); if (comp == NULL) { - GR_LOG_FATAL(d_logger, boost::format("FindNextComponent Failed")); + GR_LOG_FATAL(d_logger, "FindNextComponent Failed"); throw std::runtime_error("audio_osx_sink::setup"); } err = OpenAComponent(comp, &d_output_au); @@ -385,18 +389,20 @@ void osx_sink::setup() #if _OSX_AU_DEBUG_ - std::cerr << ((void*)(pthread_self())) << " : audio_osx_sink Parameters:" << std::endl - << " Sample Rate is " << d_input_sample_rate << std::endl - << " Max # samples to store per channel is " << d_buffer_size_samples - << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " : audio_osx_sink Parameters: Sample Rate is " + << d_input_sample_rate << " Max # samples to store per channel is " + << d_buffer_size_samples; + GR_LOG_INFO(debug_logger, msg.str()); #endif } void osx_sink::teardown() { #if _OSX_AU_DEBUG_ - std::cerr << ((void*)(pthread_self())) << " : audio_osx_sink::teardown: starting" - << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " : starting"; + GR_LOG_INFO(d_debug_logger, msg.str()); #endif OSStatus err = noErr; @@ -463,8 +469,10 @@ void osx_sink::teardown() d_output_ad_id = 0; #if _OSX_AU_DEBUG_ - std::cerr << ((void*)(pthread_self())) << " : audio_osx_sink::teardown: finished" - << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " : audio_osx_sink::teardown: finished"; + ; + GR_LOG_INFO(d_debug_logger, msg.str()); #endif } @@ -516,8 +524,10 @@ bool osx_sink::check_topology(int ninputs, int noutputs) d_n_user_channels = ninputs; #if _OSX_AU_DEBUG_ - std::cerr << ((void*)(pthread_self())) << " : audio_osx_sink::check_topology: " - << "Actual # user input channels = " << d_n_user_channels << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " : audio_osx_sink::check_topology: " + << "Actual # user input channels = " << d_n_user_channels; + GR_LOG_INFO(d_debug_logger, msg.str()); #endif return (true); @@ -607,8 +617,9 @@ bool osx_sink::start() if (!is_running() && d_output_au) { #if _OSX_AU_DEBUG_ - std::cerr << ((void*)(pthread_self())) - << " : audio_osx_sink::start: starting Output AudioUnit." << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " start: starting Output AudioUnit."; + GR_LOG_INFO(d_debug_logger, msg.str()); #endif // check channels, (re)allocate and reset buffers if/as necessary @@ -623,8 +634,9 @@ bool osx_sink::start() #if _OSX_AU_DEBUG_ else { - std::cerr << ((void*)(pthread_self())) << " : audio_osx_sink::start: " - << "already running." << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " start: already running."; + GR_LOG_INFO(d_debug_logger, msg.str()); } #endif @@ -636,15 +648,18 @@ bool osx_sink::stop() if (is_running()) { #if _OSX_AU_DEBUG_ - std::cerr << ((void*)(pthread_self())) << " : audio_osx_sink::stop: " - << "stopping Output AudioUnit." << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " stop: " + << "stopping Output AudioUnit."; + GR_LOG_INFO(d_debug_logger, msg.str()); #endif // if waiting in ::work, signal to wake up if (d_waiting_for_data) { #if _OSX_AU_DEBUG_ - std::cerr << ((void*)(pthread_self())) << " : audio_osx_sink::stop: " - << "signaling waiting condition" << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " stop: signaling waiting condition"; + GR_LOG_INFO(d_debug_logger, msg.str()); #endif d_cond_data.notify_one(); } @@ -668,8 +683,9 @@ bool osx_sink::stop() } #if _OSX_AU_DEBUG_ else { - std::cerr << ((void*)(pthread_self())) << " : audio_osx_sink::stop: " - << "already stopped." << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " stop: already stopped."; + GR_LOG_INFO(d_debug_logger, msg.str()); } #endif @@ -683,9 +699,11 @@ int osx_sink::work(int noutput_items, #if _OSX_AU_DEBUG_RENDER_ { gr::thread::scoped_lock l(d_internal); - std::cerr << ((void*)(pthread_self())) << " : audio_osx_sink::work: " - << "Starting: #OI = " << noutput_items - << ", reset = " << (d_do_reset ? "true" : "false") << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " : audio_osx_sink::work: " + << "Starting: #OI = " << noutput_items + << ", reset = " << (d_do_reset ? "true" : "false"); + GR_LOG_INFO(d_debug_logger, msg.str()); } #endif if (d_do_reset) { @@ -703,7 +721,7 @@ int osx_sink::work(int noutput_items, GR_LOG_FATAL(d_logger, boost::format("The selected output audio device ('%s') " - "is no longer available.\n") % + "is no longer available.") % d_selected_name); return (gr::block::WORK_DONE); } @@ -715,15 +733,17 @@ int osx_sink::work(int noutput_items, #if _OSX_AU_DEBUG_RENDER_ { gr::thread::scoped_lock l(d_internal); - std::cerr << ((void*)(pthread_self())) << " : audio_osx_sink::work: " - << "doing reset." << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " : audio_osx_sink::work: " + << "doing reset."; + GR_LOG_INFO(d_debug_logger, msg.str()); } #endif GR_LOG_WARN(d_logger, - boost::format("\n\nThe default output audio device has " - "changed; resetting audio.\nThere may " - "be a sound glitch while resetting.\n")); + "The default output audio device has " + "changed; resetting audio. There may " + "be a sound glitch while resetting."); // for any changes, just tear down the current // configuration, then set it up again using the user's @@ -737,8 +757,9 @@ int osx_sink::work(int noutput_items, start(); #if _OSX_AU_DEBUG_RENDER_ - std::cerr << ((void*)(pthread_self())) << " : audio_osx_sink: " - << "returning 0 after reset." << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " returning 0 after reset."; + GR_LOG_INFO(d_debug_logger, msg.str()); #endif return (0); } @@ -764,10 +785,11 @@ int osx_sink::work(int noutput_items, } #if _OSX_AU_DEBUG_RENDER_ - std::cerr << ((void*)(pthread_self())) << " : audio_osx_sink::work: " - << "qSC = " << d_queue_sample_count << ", lMC = " << l_max_count - << ", dBSC = " << d_buffer_size_samples << ", #OI = " << noutput_items - << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " : audio_osx_sink::work: " + << "qSC = " << d_queue_sample_count << ", lMC = " << l_max_count + << ", dBSC = " << d_buffer_size_samples << ", #OI = " << noutput_items; + GR_LOG_INFO(d_debug_logger, msg.str()); #endif if (d_queue_sample_count > l_max_count) { @@ -783,15 +805,19 @@ int osx_sink::work(int noutput_items, // release control so-as to allow data to be retrieved; // block until there is data to return #if _OSX_AU_DEBUG_RENDER_ - std::cerr << ((void*)(pthread_self())) << " : audio_osx_sink::work: " - << "waiting." << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " work: " + << "waiting."; + GR_LOG_INFO(d_debug_logger, msg.str()); #endif d_waiting_for_data = true; d_cond_data.wait(l); d_waiting_for_data = false; #if _OSX_AU_DEBUG_RENDER_ - std::cerr << ((void*)(pthread_self())) << " : audio_osx_sink::work: " - << "done waiting." << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " work: " + << "done waiting"; + GR_LOG_INFO(d_debug_logger, msg.str()); #endif // the condition's 'notify' was called; acquire control to // keep thread safe @@ -800,8 +826,10 @@ int osx_sink::work(int noutput_items, // up the next time this method is called. if (d_do_reset) { #if _OSX_AU_DEBUG_RENDER_ - std::cerr << ((void*)(pthread_self())) << " : audio_osx_sink::work: " - << "returning 0 for reset." << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " work: " + << "returning 0 for reset."; + GR_LOG_INFO(d_debug_logger, msg.str()); #endif return (0); } @@ -847,10 +875,11 @@ int osx_sink::work(int noutput_items, } #if _OSX_AU_DEBUG_RENDER_ - std::cerr << ((void*)(pthread_self())) << " : audio_osx_sink::work: " - << "returning: #OI = " << noutput_items - << ", qSC = " << d_queue_sample_count << ", bSS = " << d_buffer_size_samples - << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " work: " + << "returning: #OI = " << noutput_items << ", qSC = " << d_queue_sample_count + << ", bSS = " << d_buffer_size_samples; + GR_LOG_INFO(d_debug_logger, msg.str()); #endif return (noutput_items); @@ -873,10 +902,11 @@ OSStatus osx_sink::au_output_callback(void* in_ref_con, gr::thread::scoped_lock l(This->d_internal); #if _OSX_AU_DEBUG_RENDER_ - std::cerr << ((void*)(pthread_self())) << " : audio_osx_sink::au_output_callback: " - << "starting: qSC = " << This->d_queue_sample_count - << ", in#F = " << in_number_frames << ", in#C = " << This->d_n_user_channels - << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " : audio_osx_sink::au_output_callback: " + << "starting: qSC = " << This->d_queue_sample_count + << ", in#F = " << in_number_frames << ", in#C = " << This->d_n_user_channels; + GR_LOG_INFO(d_debug_logger, msg.str()); #endif if (This->d_queue_sample_count < in_number_frames) { @@ -898,11 +928,12 @@ OSStatus osx_sink::au_output_callback(void* in_ref_con, int rv = This->d_buffers[nn]->dequeue(out_buffer, &t_n_output_items); if ((rv != 1) || (t_n_output_items != in_number_frames)) { - - std::cerr << "audio_osx_sink::au_output_callback: " - << "number of available items changing " - << "unexpectedly (should never happen): was " - << in_number_frames << " now " << t_n_output_items << std::endl; + std::ostringstream msg; + msg << "audio_osx_sink::au_output_callback: " + << "number of available items changing " + << "unexpectedly (should never happen): was " << in_number_frames + << " now " << t_n_output_items; + GR_LOG_ERROR(d_logger, msg.str()); err = kAudioUnitErr_TooManyFramesToProcess; } } @@ -914,17 +945,19 @@ OSStatus osx_sink::au_output_callback(void* in_ref_con, if (This->d_waiting_for_data) { #if _OSX_AU_DEBUG_RENDER_ - std::cerr << ((void*)(pthread_self())) - << " : audio_osx_sink::au_output_callback: " - << "signaling waiting condition" << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " au_output_callback: " + << "signaling waiting condition"; + GR_LOG_INFO(d_debug_logger, msg.str()); #endif This->d_cond_data.notify_one(); } #if _OSX_AU_DEBUG_RENDER_ - std::cerr << ((void*)(pthread_self())) << " : audio_osx_sink::au_output_callback: " - << "returning: qSC = " << This->d_queue_sample_count << ", err = " << err - << std::endl; + std::ostringstream msg; + msg << ((void*)(pthread_self())) << " au_output_callback: " + << "returning: qSC = " << This->d_queue_sample_count << ", err = " << err; + GR_LOG_INFO(d_debug_logger, msg.str()); #endif return (err); diff --git a/gr-audio/lib/portaudio/portaudio_sink.cc b/gr-audio/lib/portaudio/portaudio_sink.cc index f19936e773..47c173c9cb 100644 --- a/gr-audio/lib/portaudio/portaudio_sink.cc +++ b/gr-audio/lib/portaudio/portaudio_sink.cc @@ -24,6 +24,7 @@ #include <stdio.h> #include <string.h> #include <unistd.h> +#include <future> #include <iostream> #include <stdexcept> #ifdef _MSC_VER @@ -58,17 +59,24 @@ void portaudio_sink::create_ringbuffer(void) int bufsize_samples = d_portaudio_buffer_size_frames * d_output_parameters.channelCount; - if (d_verbose) { - fprintf(stderr, - "ring buffer size = %d frames\n", - N_BUFFERS * bufsize_samples / d_output_parameters.channelCount); - } + if (d_verbose) + GR_LOG_INFO(d_debug_logger, + boost::format("ring buffer size = %d frames") % + (N_BUFFERS * bufsize_samples / d_output_parameters.channelCount)); // FYI, the buffer indices are in units of samples. d_writer = gr::make_buffer(N_BUFFERS * bufsize_samples, sizeof(sample_t)); d_reader = gr::buffer_add_reader(d_writer, 0); } + +void portaudio_underrun_notification(gr::logger_ptr logger) +{ + ssize_t r = ::write(2, "aU", 2); + if (r == -1) { + GR_LOG_ERROR(logger, "portaudio_source_callback write error to stderr."); + } +} /* * This routine will be called by the PortAudio engine when audio is needed. * It may called at interrupt level on some machines so don't do anything @@ -83,7 +91,7 @@ int portaudio_sink_callback(const void* inputBuffer, PaStreamCallbackFlags statusFlags, void* arg) { - portaudio_sink* self = (portaudio_sink*)arg; + auto self = reinterpret_cast<portaudio_sink*>(arg); int nreqd_samples = framesPerBuffer * self->d_output_parameters.channelCount; int navail_samples = self->d_reader->items_available(); @@ -106,13 +114,7 @@ int portaudio_sink_callback(const void* inputBuffer, } else { // underrun - self->d_nunderuns++; - ssize_t r = ::write(2, "aU", 2); // FIXME change to non-blocking call - if (r == -1) { - perror("audio_portaudio_source::portaudio_source_callback write error to " - "stderr."); - } - + std::async(&portaudio_underrun_notification, self->d_logger); // FIXME we should transfer what we've got and pad the rest memset(outputBuffer, 0, nreqd_samples * sizeof(sample_t)); @@ -139,12 +141,9 @@ portaudio_sink::portaudio_sink(int sampling_rate, d_stream(0), d_ringbuffer_mutex(), d_ringbuffer_cond(), - d_ringbuffer_ready(false), - d_nunderuns(0) + d_ringbuffer_ready(false) { memset(&d_output_parameters, 0, sizeof(d_output_parameters)); - // if(LOGGING) - // d_log = gri_logger::singleton(); PaError err; int i, numDevices; @@ -167,38 +166,34 @@ portaudio_sink::portaudio_sink(int sampling_rate, if (d_device_name.empty()) { // FIXME Get smarter about picking something - fprintf(stderr, "\nUsing Default Device\n"); + GR_LOG_INFO(d_debug_logger, "Using Default Devicee"); device = Pa_GetDefaultOutputDevice(); deviceInfo = Pa_GetDeviceInfo(device); - fprintf(stderr, - "%s is the chosen device using %s as the host\n", - deviceInfo->name, - Pa_GetHostApiInfo(deviceInfo->hostApi)->name); + GR_LOG_ERROR(d_logger, + boost::format("%s is the chosen device using %s as the host") % + deviceInfo->name % Pa_GetHostApiInfo(deviceInfo->hostApi)->name); } else { bool found = false; - fprintf(stderr, "\nTest Devices\n"); + GR_LOG_INFO(d_debug_logger, "Test Devices"); for (i = 0; i < numDevices; i++) { deviceInfo = Pa_GetDeviceInfo(i); - fprintf(stderr, "Testing device name: %s", deviceInfo->name); - + GR_LOG_INFO(d_debug_logger, + boost::format("Testing device name: %s...") % deviceInfo->name); if (deviceInfo->maxOutputChannels <= 0) { - fprintf(stderr, "\n"); continue; } if (strstr(deviceInfo->name, d_device_name.c_str())) { - fprintf(stderr, " Chosen!\n"); + GR_LOG_INFO(d_debug_logger, " Chosen!"); device = i; - fprintf(stderr, - "%s using %s as the host\n", - d_device_name.c_str(), - Pa_GetHostApiInfo(deviceInfo->hostApi)->name), - fflush(stderr); + GR_LOG_INFO(d_debug_logger, + boost::format("%s using %s as the host") % + d_device_name.c_str() % + Pa_GetHostApiInfo(deviceInfo->hostApi)->name); found = true; deviceInfo = Pa_GetDeviceInfo(device); i = numDevices; // force loop exit - } else - fprintf(stderr, "\n"), fflush(stderr); + } } if (!found) { @@ -240,11 +235,9 @@ bool portaudio_sink::check_topology(int ninputs, int noutputs) #if 1 d_portaudio_buffer_size_frames = (int)(0.0213333333 * d_sampling_rate + 0.5); // Force 1024 frame buffers at 48000 - fprintf(stderr, - "Latency = %8.5f, requested sampling_rate = %g\n", // Force latency - // to 21.3333333.. ms - 0.0213333333, - (double)d_sampling_rate); + GR_LOG_ERROR(d_logger, + boost::format("Latency = %8.5f, requested sampling_rate = %g") % + 0.0213333333 % (double)d_sampling_rate); #endif err = Pa_OpenStream(&d_stream, NULL, // No input @@ -261,15 +254,19 @@ bool portaudio_sink::check_topology(int ninputs, int noutputs) } #if 0 - const PaStreamInfo *psi = Pa_GetStreamInfo(d_stream); - - d_portaudio_buffer_size_frames = (int)(d_output_parameters.suggestedLatency * psi->sampleRate); - fprintf(stderr, "Latency = %7.4f, psi->sampleRate = %g\n", - d_output_parameters.suggestedLatency, psi->sampleRate); + const PaStreamInfo *psi = Pa_GetStreamInfo(d_stream); + + d_portaudio_buffer_size_frames = (int)(d_output_parameters.suggestedLatency * psi->sampleRate); + GR_LOG_ERROR( + d_logger, + boost::format("Latency = %7.4f, psi->sampleRate = %g") % + d_input_parameters.suggestedLatency + % psi->sampleRate + ); #endif - - fprintf( - stderr, "d_portaudio_buffer_size_frames = %d\n", d_portaudio_buffer_size_frames); + GR_LOG_ERROR(d_logger, + boost::format("d_portaudio_buffer_size_frames = %d") % + d_portaudio_buffer_size_frames); assert(d_portaudio_buffer_size_frames != 0); @@ -350,11 +347,9 @@ int portaudio_sink::work(int noutput_items, void portaudio_sink::output_error_msg(const char* msg, int err) { - fprintf(stderr, - "audio_portaudio_sink[%s]: %s: %s\n", - d_device_name.c_str(), - msg, - Pa_GetErrorText(err)); + GR_LOG_ERROR(d_logger, + boost::format("%s: %s %s") % d_device_name.c_str() % msg % + Pa_GetErrorText(err)); } void portaudio_sink::bail(const char* msg, int err) diff --git a/gr-audio/lib/portaudio/portaudio_sink.h b/gr-audio/lib/portaudio/portaudio_sink.h index 80d3bb94eb..629a96e7e8 100644 --- a/gr-audio/lib/portaudio/portaudio_sink.h +++ b/gr-audio/lib/portaudio/portaudio_sink.h @@ -12,6 +12,7 @@ #include <gnuradio/audio/sink.h> #include <gnuradio/buffer.h> +#include <gnuradio/logger.h> #include <gnuradio/thread/thread.h> #include <portaudio.h> #include <stdexcept> @@ -50,9 +51,6 @@ class portaudio_sink : public sink gr::thread::condition_variable d_ringbuffer_cond; bool d_ringbuffer_ready; - // random stats - int d_nunderuns; // count of underruns - // gri_logger_sptr d_log; // handle to non-blocking logging instance void output_error_msg(const char* msg, int err); void bail(const char* msg, int err); diff --git a/gr-audio/lib/portaudio/portaudio_source.cc b/gr-audio/lib/portaudio/portaudio_source.cc index 7f5b2aeb15..f742549f6b 100644 --- a/gr-audio/lib/portaudio/portaudio_source.cc +++ b/gr-audio/lib/portaudio/portaudio_source.cc @@ -58,11 +58,10 @@ void portaudio_source::create_ringbuffer(void) int bufsize_samples = d_portaudio_buffer_size_frames * d_input_parameters.channelCount; - if (d_verbose) { - fprintf(stderr, - "ring buffer size = %d frames\n", - N_BUFFERS * bufsize_samples / d_input_parameters.channelCount); - } + if (d_verbose) + GR_LOG_INFO(d_debug_logger, + boost::format("ring buffer size = %d frames") % + (N_BUFFERS * bufsize_samples / d_input_parameters.channelCount)); // FYI, the buffer indices are in units of samples. d_writer = gr::make_buffer(N_BUFFERS * bufsize_samples, sizeof(sample_t)); @@ -113,8 +112,10 @@ int portaudio_source_callback(const void* inputBuffer, self->d_noverruns++; ssize_t r = ::write(2, "aO", 2); // FIXME change to non-blocking call if (r == -1) { - perror("audio_portaudio_source::portaudio_source_callback write error to " - "stderr."); + gr::logger_ptr logger, debug_logger; + gr::configure_default_loggers( + logger, debug_logger, "portaudio_source_callback"); + GR_LOG_ERROR(logger, boost::format("write error: %s") % strerror(errno)); } self->d_ringbuffer_ready = false; @@ -143,8 +144,6 @@ portaudio_source::portaudio_source(int sampling_rate, d_noverruns(0) { memset(&d_input_parameters, 0, sizeof(d_input_parameters)); - // if(LOGGING) - // d_log = gri_logger::singleton(); PaError err; int i, numDevices; @@ -169,33 +168,30 @@ portaudio_source::portaudio_source(int sampling_rate, // FIXME Get smarter about picking something device = Pa_GetDefaultInputDevice(); deviceInfo = Pa_GetDeviceInfo(device); - fprintf(stderr, - "%s is the chosen device using %s as the host\n", - deviceInfo->name, - Pa_GetHostApiInfo(deviceInfo->hostApi)->name); + GR_LOG_ERROR(d_logger, + boost::format("%s is the chosen device using %s as the host") % + deviceInfo->name % Pa_GetHostApiInfo(deviceInfo->hostApi)->name); } else { bool found = false; - + GR_LOG_INFO(d_debug_logger, "Test Devices"); for (i = 0; i < numDevices; i++) { deviceInfo = Pa_GetDeviceInfo(i); - fprintf(stderr, "Testing device name: %s", deviceInfo->name); + GR_LOG_INFO(d_debug_logger, + boost::format("Testing device name: %s...") % deviceInfo->name); if (deviceInfo->maxInputChannels <= 0) { - fprintf(stderr, "\n"); continue; } if (strstr(deviceInfo->name, d_device_name.c_str())) { - fprintf(stderr, " Chosen!\n"); + GR_LOG_INFO(d_debug_logger, " Chosen!"); device = i; - fprintf(stderr, - "%s using %s as the host\n", - d_device_name.c_str(), - Pa_GetHostApiInfo(deviceInfo->hostApi)->name), - fflush(stderr); + GR_LOG_INFO(d_debug_logger, + boost::format("%s using %s as the host") % + d_device_name.c_str() % + Pa_GetHostApiInfo(deviceInfo->hostApi)->name); found = true; deviceInfo = Pa_GetDeviceInfo(device); i = numDevices; // force loop exit - } else - fprintf(stderr, "\n"), fflush(stderr); + } } if (!found) { @@ -236,11 +232,9 @@ bool portaudio_source::check_topology(int ninputs, int noutputs) #if 1 d_portaudio_buffer_size_frames = (int)(0.0213333333 * d_sampling_rate + 0.5); // Force 512 frame buffers at 48000 - fprintf(stderr, - "Latency = %8.5f, requested sampling_rate = %g\n", // Force latency - // to 21.3333333.. ms - 0.0213333333, - (double)d_sampling_rate); + GR_LOG_ERROR(d_logger, + boost::format("Latency = %8.5f, requested sampling_rate = %g") % + 0.0213333333 % (double)d_sampling_rate); #endif err = Pa_OpenStream(&d_stream, &d_input_parameters, @@ -257,15 +251,16 @@ bool portaudio_source::check_topology(int ninputs, int noutputs) } #if 0 - const PaStreamInfo *psi = Pa_GetStreamInfo(d_stream); + const PaStreamInfo *psi = Pa_GetStreamInfo(d_stream); - d_portaudio_buffer_size_frames = (int)(d_input_parameters.suggestedLatency * psi->sampleRate); - fprintf(stderr, "Latency = %7.4f, psi->sampleRate = %g\n", - d_input_parameters.suggestedLatency, psi->sampleRate); + d_portaudio_buffer_size_frames = (int)(d_input_parameters.suggestedLatency * psi->sampleRate); + GR_LOG_ERROR(d_logger, + boost::format("Latency = %7.4f, psi->sampleRate = %g") % + d_input_parameters.suggestedLatency % psi->sampleRate); #endif - - fprintf( - stderr, "d_portaudio_buffer_size_frames = %d\n", d_portaudio_buffer_size_frames); + GR_LOG_ERROR(d_logger, + boost::format("d_portaudio_buffer_size_frames = %d") % + d_portaudio_buffer_size_frames); assert(d_portaudio_buffer_size_frames != 0); @@ -360,11 +355,9 @@ int portaudio_source::work(int noutput_items, void portaudio_source::output_error_msg(const char* msg, int err) { - fprintf(stderr, - "audio_portaudio_source[%s]: %s: %s\n", - d_device_name.c_str(), - msg, - Pa_GetErrorText(err)); + GR_LOG_ERROR(d_logger, + boost::format("%s: %s %s") % d_device_name.c_str() % msg % + Pa_GetErrorText(err)); } void portaudio_source::bail(const char* msg, int err) diff --git a/gr-audio/lib/portaudio/portaudio_source.h b/gr-audio/lib/portaudio/portaudio_source.h index 375743aa9c..4ced8c4b8b 100644 --- a/gr-audio/lib/portaudio/portaudio_source.h +++ b/gr-audio/lib/portaudio/portaudio_source.h @@ -13,6 +13,7 @@ #include <gnuradio/audio/source.h> #include <gnuradio/buffer.h> +#include <gnuradio/logger.h> #include <gnuradio/thread/thread.h> #include <portaudio.h> #include <stdexcept> diff --git a/gr-audio/lib/windows/windows_sink.cc b/gr-audio/lib/windows/windows_sink.cc index edff4c7307..9c60265307 100644 --- a/gr-audio/lib/windows/windows_sink.cc +++ b/gr-audio/lib/windows/windows_sink.cc @@ -89,10 +89,11 @@ windows_sink::windows_sink(int sampling_freq, d_wave_write_event = CreateEvent(NULL, FALSE, FALSE, NULL); if (open_waveout_device() < 0) { - perror("audio_windows_sink:open_waveout_device() failed\n"); + GR_LOG_ERROR(d_logger, + boost::format("open_waveout_device() failed: %s") % strerror(errno)); throw std::runtime_error("audio_windows_sink:open_waveout_device() failed"); - } else if (verbose) { - GR_LOG_INFO(d_logger, "Opened windows waveout device"); + } else { + GR_LOG_INFO(d_debug_logger, "Opened windows waveout device"); } d_buffers = new LPWAVEHDR[nPeriods]; for (int i = 0; i < nPeriods; i++) { @@ -102,12 +103,11 @@ windows_sink::windows_sink(int sampling_freq, d_buffers[i]->dwBufferLength = d_buffer_size; d_buffers[i]->lpData = new CHAR[d_buffer_size]; } - if (verbose) - GR_LOG_INFO( - d_logger, - boost::format( - "Initialized %1% %2%ms audio buffers, total memory used: %3$0.2fkB") % - (nPeriods) % (CHUNK_TIME * 1000) % ((d_buffer_size * nPeriods) / 1024.0)); + GR_LOG_INFO( + d_debug_logger, + boost::format( + "Initialized %1% %2% ms audio buffers, total memory used: %3$0.2f kB") % + (nPeriods) % (CHUNK_TIME * 1000) % ((d_buffer_size * nPeriods) / 1024.0)); } windows_sink::~windows_sink() @@ -178,9 +178,12 @@ int windows_sink::work(int noutput_items, // let's just fail and give some debugging information about the status of // the buffers. for (int i = 0; i < nPeriods; i++) { - printf("%d: %d\n", i, d_buffers[i]->dwFlags); + GR_LOG_ERROR( + d_logger, "audio buffer %d: %d", i, d_buffers[i]->dwFlags); } - perror("audio_windows_sink: no audio buffers available"); + GR_LOG_ERROR(d_logger, + boost::format("no audio buffers available: %s") % + strerror(errno)); return -1; } } @@ -209,7 +212,7 @@ int windows_sink::work(int noutput_items, break; } if (write_waveout(chosen_header) < 0) { - perror("audio_windows_sink: write failed"); + GR_LOG_ERROR(d_logger, boost::format("write failed: %s") % strerror(errno)); } samples_sent += samples_tosend; } @@ -253,8 +256,8 @@ UINT windows_sink::find_device(std::string szDeviceName) if (num < num_devices) { result = num; } else { - GR_LOG_INFO(d_logger, - boost::format("Warning: waveOut deviceID %d was not found, " + GR_LOG_WARN(d_logger, + boost::format("waveOut deviceID %d was not found. " "defaulting to WAVE_MAPPER") % num); result = WAVE_MAPPER; @@ -265,27 +268,32 @@ UINT windows_sink::find_device(std::string szDeviceName) for (UINT i = 0; i < num_devices; i++) { WAVEOUTCAPS woc; if (waveOutGetDevCaps(i, &woc, sizeof(woc)) != MMSYSERR_NOERROR) { - perror("Error: Could not retrieve wave out device capabilities for " - "device"); + GR_LOG_ERROR(d_logger, + boost::format("Could not retrieve wave out device " + "capabilities for %s device") % + strerror(errno)); return -1; } if (woc.szPname == szDeviceName) { result = i; } - if (verbose) - GR_LOG_INFO(d_logger, + if (verbose) { + GR_LOG_INFO(d_debug_logger, boost::format("WaveOut Device %d: %s") % i % woc.szPname); + } } if (result == -1) { - GR_LOG_INFO(d_logger, - boost::format("Warning: waveOut device '%s' was not found, " + GR_LOG_WARN(d_logger, + boost::format("waveOut device '%s' was not found, " "defaulting to WAVE_MAPPER") % szDeviceName); result = WAVE_MAPPER; } } } else { - perror("Error: No WaveOut devices present or accessible"); + GR_LOG_ERROR(d_logger, + boost::format("No WaveOut devices present or accessible: %s") % + strerror(errno)); } return result; } @@ -311,16 +319,19 @@ int windows_sink::open_waveout_device(void) // and stick with WAVE_MAPPER u_device_id = find_device(d_device_name); if (verbose) - GR_LOG_INFO(d_logger, boost::format("waveOut Device ID: %1%") % (u_device_id)); + GR_LOG_INFO(d_debug_logger, + boost::format("waveOut Device ID: %1%") % (u_device_id)); // Check if the sampling rate/bits/channels are good to go with the device. MMRESULT supported = is_format_supported(&wave_format, u_device_id); if (supported != MMSYSERR_NOERROR) { char err_msg[50]; waveOutGetErrorText(supported, err_msg, 50); - GR_LOG_INFO(d_logger, boost::format("format error: %s") % err_msg); - perror("audio_windows_sink: Requested audio format is not supported by device " - "driver"); + GR_LOG_INFO(d_debug_logger, boost::format("format error: %s") % err_msg); + GR_LOG_ERROR( + d_logger, + boost::format("Requested audio format is not supported by device %s driver") % + strerror(errno)); return -1; } @@ -332,10 +343,11 @@ int windows_sink::open_waveout_device(void) 0, CALLBACK_EVENT | WAVE_ALLOWSYNC); - if (result) { - perror("audio_windows_sink: Failed to open waveform output device."); - return -1; - } + if (result) + GR_LOG_ERROR(d_logger, + boost::format("Failed to open waveform output device. %s") % + strerr(errno)); + return -1; return 0; } @@ -350,30 +362,32 @@ int windows_sink::write_waveout(LPWAVEHDR lp_wave_hdr) w_result = waveOutPrepareHeader(d_h_waveout, lp_wave_hdr, sizeof(WAVEHDR)); if (w_result != 0) { - perror("audio_windows_sink: Failed to waveOutPrepareHeader"); + GR_LOG_ERROR(d_logger, + boost::format("Failed to waveOutPrepareHeader %s") % strerr(errno)); return -1; } w_result = waveOutWrite(d_h_waveout, lp_wave_hdr, sizeof(WAVEHDR)); if (w_result != 0) { - perror("audio_windows_sink: Failed to write block to device"); + GR_LOG_ERROR(d_logger, + boost::format("Failed to write block to device %s") % strerr(errno)); switch (w_result) { case MMSYSERR_INVALHANDLE: - fprintf(stderr, "Specified device handle is invalid.\n"); + GR_LOG_ERROR(d_logger, "Specified device handle is invalid"); break; case MMSYSERR_NODRIVER: - fprintf(stderr, " No device driver is present.\n"); + GR_LOG_ERROR(d_logger, "No device driver is present"); break; case MMSYSERR_NOMEM: - fprintf(stderr, " Unable to allocate or lock memory.\n"); + GR_LOG_ERROR(d_logger, "Unable to allocate or lock memory"); break; case WAVERR_UNPREPARED: - fprintf(stderr, - " The data block pointed to by the pwh parameter hasn't been " - "prepared.\n"); + GR_LOG_ERROR(d_logger, + "The data block pointed to by the pwh parameter hasn't " + "been prepared."); break; default: - fprintf(stderr, "Unknown error %i\n", w_result); + GR_LOG_ERROR(d_logger, boost::format("Unknown error %i") % w_result); } waveOutUnprepareHeader(d_h_waveout, lp_wave_hdr, sizeof(WAVEHDR)); return -1; diff --git a/gr-audio/lib/windows/windows_sink.h b/gr-audio/lib/windows/windows_sink.h index b41f2a816b..9a15c33ed9 100644 --- a/gr-audio/lib/windows/windows_sink.h +++ b/gr-audio/lib/windows/windows_sink.h @@ -18,6 +18,7 @@ #include <windows.h> #include <gnuradio/audio/sink.h> +#include <gnuradio/logger.h> #include <string> namespace gr { diff --git a/gr-audio/lib/windows/windows_source.cc b/gr-audio/lib/windows/windows_source.cc index 99435a9f44..465c62f028 100644 --- a/gr-audio/lib/windows/windows_source.cc +++ b/gr-audio/lib/windows/windows_source.cc @@ -90,10 +90,11 @@ windows_source::windows_source(int sampling_freq, const std::string device_name) (wave_format.wBitsPerSample / 8); // room for 16-bit audio on one channel. if (open_wavein_device() < 0) { - perror("audio_windows_source:open_wavein_device() failed\n"); + GR_LOG_ERROR(d_logger, + boost::format("open_wavein_device() failed %s" % strerror(errno))); throw std::runtime_error("audio_windows_source:open_wavein_device() failed"); - } else if (verbose) { - GR_LOG_INFO(d_logger, "Opened windows wavein device"); + } else { + GR_LOG_INFO(d_debug_logger, "Opened windows wavein device"); } lp_buffers = new LPWAVEHDR[nPeriods]; for (int i = 0; i < nPeriods; i++) { @@ -105,18 +106,21 @@ windows_source::windows_source(int sampling_freq, const std::string device_name) lp_buffer->lpData = new CHAR[d_buffer_size]; MMRESULT w_result = waveInPrepareHeader(d_h_wavein, lp_buffer, sizeof(WAVEHDR)); if (w_result != 0) { - perror("audio_windows_source: Failed to waveInPrepareHeader"); - throw std::runtime_error("audio_windows_source:open_wavein_device() failed"); + GR_LOG_ERROR( + d_logger, + boost::format("Failed to waveInPrepareHeader %s" % strerror(errno))); + throw std::runtime_error("open_wavein_device() failed"); } waveInAddBuffer(d_h_wavein, lp_buffer, sizeof(WAVEHDR)); } waveInStart(d_h_wavein); - if (verbose) + if (verbose) { GR_LOG_INFO( - d_logger, + d_debug_logger, boost::format( - "Initialized %1% %2%ms audio buffers, total memory used: %3$0.2fkB") % + "Initialized %1% %2% ms audio buffers, total memory used: %3$0.2f kiB") % (nPeriods) % (CHUNK_TIME * 1000) % ((d_buffer_size * nPeriods) / 1024.0)); + } } windows_source::~windows_source() @@ -226,8 +230,8 @@ UINT windows_source::find_device(std::string szDeviceName) if (num < num_devices) { result = num; } else { - GR_LOG_INFO(d_logger, - boost::format("Warning: waveIn deviceID %d was not found, " + GR_LOG_WARN(d_logger, + boost::format("waveIn deviceID %d was not found, " "defaulting to WAVE_MAPPER") % num); result = WAVE_MAPPER; @@ -238,19 +242,21 @@ UINT windows_source::find_device(std::string szDeviceName) for (UINT i = 0; i < num_devices; i++) { WAVEINCAPS woc; if (waveInGetDevCaps(i, &woc, sizeof(woc)) != MMSYSERR_NOERROR) { - perror("Error: Could not retrieve wave out device capabilities for " - "device"); + GR_LOG_ERROR(d_logger, + boost::format("Could not retrieve wave out device " + "capabilities for device %s" % + strerror(errno))); return -1; } if (woc.szPname == szDeviceName) { result = i; } if (verbose) - GR_LOG_INFO(d_logger, + GR_LOG_INFO(d_debug_logger, boost::format("WaveIn Device %d: %s") % i % woc.szPname); } if (result == -1) { - GR_LOG_INFO(d_logger, + GR_LOG_INFO(d_debug_logger, boost::format("Warning: waveIn device '%s' was not found, " "defaulting to WAVE_MAPPER") % szDeviceName); @@ -258,7 +264,9 @@ UINT windows_source::find_device(std::string szDeviceName) } } } else { - perror("Error: No WaveIn devices present or accessible"); + GR_LOG_ERROR(d_logger, + boost::format("No WaveIn devices present or accessible: %s" % + strerror(errno))); } return result; } @@ -284,16 +292,19 @@ int windows_source::open_wavein_device(void) // and stick with WAVE_MAPPER u_device_id = find_device(d_device_name); if (verbose) - GR_LOG_INFO(d_logger, boost::format("waveIn Device ID: %1%") % (u_device_id)); + GR_LOG_INFO(d_debug_logger, + boost::format("waveIn Device ID: %1%") % (u_device_id)); // Check if the sampling rate/bits/channels are good to go with the device. MMRESULT supported = is_format_supported(&wave_format, u_device_id); if (supported != MMSYSERR_NOERROR) { char err_msg[50]; waveInGetErrorText(supported, err_msg, 50); - GR_LOG_INFO(d_logger, boost::format("format error: %s") % err_msg); - perror("audio_windows_source: Requested audio format is not supported by device " - "driver"); + GR_LOG_INFO(d_debug_logger, boost::format("format error: %s") % err_msg); + GR_LOG_ERROR( + d_logger, + boost::format("Requested audio format is not supported by device driver: %s" % + strerror(errno))); return -1; } @@ -306,7 +317,9 @@ int windows_source::open_wavein_device(void) CALLBACK_FUNCTION | WAVE_ALLOWSYNC); if (result) { - perror("audio_windows_source: Failed to open waveform output device."); + GR_LOG_ERROR( + d_logger, + boost::format("Failed to open waveform output device: %s" % strerror(errno))); return -1; } return 0; @@ -318,7 +331,9 @@ static void CALLBACK read_wavein( // Ignore WIM_OPEN and WIM_CLOSE messages if (uMsg == WIM_DATA) { if (!dwInstance) { - perror("audio_windows_source: callback function missing buffer queue"); + GR_LOG_ERROR(d_logger, + boost::format("callback function missing buffer queue: %s" % + strerror(errno))); } LPWAVEHDR lp_wave_hdr = (LPWAVEHDR)dwParam1; // The new audio data boost::lockfree::spsc_queue<LPWAVEHDR>* q = |