diff --git a/Audio/soundin.cpp b/Audio/soundin.cpp index 53a29799c..d9bc78446 100644 --- a/Audio/soundin.cpp +++ b/Audio/soundin.cpp @@ -184,13 +184,13 @@ void SoundInput::reset (bool report_dropped_frames) { LOG_WARN ("Detected dropped audio source samples: " << m_stream->format ().framesForDuration (lost_usec) - << " (" << std::setprecision (4) << lost_usec / 1.e6 << " S)") + << " (" << std::setprecision (4) << lost_usec / 1.e6 << " S)"); } else if (std::abs (lost_usec) > 5 * 48000) { LOG_ERROR ("Detected excessive dropped audio source samples: " << m_stream->format ().framesForDuration (lost_usec) - << " (" << std::setprecision (4) << lost_usec / 1.e6 << " S)") + << " (" << std::setprecision (4) << lost_usec / 1.e6 << " S)"); } } cummulative_lost_usec_ = elapsed_usecs - m_stream->processedUSecs (); diff --git a/Logger.hpp b/Logger.hpp index 5d497943f..0eed8aae2 100644 --- a/Logger.hpp +++ b/Logger.hpp @@ -35,16 +35,16 @@ namespace Logger BOOST_LOG_SEV (LOGGER, boost::log::trivial::LEVEL) \ << boost::log::add_value ("Line", __LINE__) \ << boost::log::add_value ("File", __FILE__) \ - << boost::log::add_value ("Function", __FUNCTION__) << ARG; + << boost::log::add_value ("Function", __FUNCTION__) << ARG /// System Log macros. /// TRACE < DEBUG < INFO < WARN < ERROR < FATAL -#define LOG_TRACE(ARG) LOG_LOG_LOCATION (sys::get(), trace, ARG); -#define LOG_DEBUG(ARG) LOG_LOG_LOCATION (sys::get(), debug, ARG); -#define LOG_INFO(ARG) LOG_LOG_LOCATION (sys::get(), info, ARG); -#define LOG_WARN(ARG) LOG_LOG_LOCATION (sys::get(), warning, ARG); -#define LOG_ERROR(ARG) LOG_LOG_LOCATION (sys::get(), error, ARG); -#define LOG_FATAL(ARG) LOG_LOG_LOCATION (sys::get(), fatal, ARG); +#define LOG_TRACE(ARG) LOG_LOG_LOCATION (sys::get(), trace, ARG) +#define LOG_DEBUG(ARG) LOG_LOG_LOCATION (sys::get(), debug, ARG) +#define LOG_INFO(ARG) LOG_LOG_LOCATION (sys::get(), info, ARG) +#define LOG_WARN(ARG) LOG_LOG_LOCATION (sys::get(), warning, ARG) +#define LOG_ERROR(ARG) LOG_LOG_LOCATION (sys::get(), error, ARG) +#define LOG_FATAL(ARG) LOG_LOG_LOCATION (sys::get(), fatal, ARG) /// Data Log macros. Does not include LINE, FILE, FUNCTION. /// TRACE < DEBUG < INFO < WARN < ERROR < FATAL diff --git a/Network/PSKReporter.cpp b/Network/PSKReporter.cpp index 35c56f23f..c072860f8 100644 --- a/Network/PSKReporter.cpp +++ b/Network/PSKReporter.cpp @@ -22,6 +22,7 @@ #include #endif +#include "Logger.hpp" #include "Configuration.hpp" #include "pimpl_impl.hpp" @@ -46,9 +47,12 @@ class PSKReporter::impl final { Q_OBJECT + using logger_type = boost::log::sources::severity_channel_logger_mt; + public: impl (PSKReporter * self, Configuration const * config, QString const& program_info) - : self_ {self} + : logger_ {boost::log::keywords::channel = "PSKRPRT"} + , self_ {self} , config_ {config} , sequence_number_ {0u} , send_descriptors_ {0} @@ -72,6 +76,7 @@ public: if (socket_ && QAbstractSocket::UdpSocket == socket_->socketType ()) { + LOG_LOG_LOCATION (logger_, trace, "enable descriptor resend"); // send templates again send_descriptors_ = 3; // three times // send receiver data set again @@ -91,6 +96,7 @@ public: && QAbstractSocket::UnconnectedState != socket_->state () && QAbstractSocket::ClosingState != socket_->state ()) { + LOG_LOG_LOCATION (logger_, trace, "create/recreate socket"); // handle re-opening asynchronously auto connection = QSharedPointer::create (); *connection = connect (socket_.data (), &QAbstractSocket::disconnected, [this, connection] () { @@ -110,6 +116,7 @@ public: void handle_socket_error (QAbstractSocket::SocketError e) { + LOG_LOG_LOCATION (logger_, trace, "err: " << e); switch (e) { case QAbstractSocket::RemoteHostClosedError: @@ -132,12 +139,14 @@ public: // be called from the disconnected handler above. if (config_->psk_reporter_tcpip ()) { + LOG_LOG_LOCATION (logger_, trace, "create TCP/IP socket"); socket_.reset (new QTcpSocket, &QObject::deleteLater); send_descriptors_ = 1; send_receiver_data_ = 1; } else { + LOG_LOG_LOCATION (logger_, trace, "create UDP/IP socket"); socket_.reset (new QUdpSocket, &QObject::deleteLater); send_descriptors_ = 3; send_receiver_data_ = 3; @@ -154,6 +163,7 @@ public: // use this for pseudo connection with UDP, allows us to use // QIODevice::write() instead of QUDPSocket::writeDatagram() socket_->connectToHost (HOST, SERVICE_PORT, QAbstractSocket::WriteOnly); + LOG_LOG_LOCATION (logger_, debug, "remote host: " << HOST << " port: " << SERVICE_PORT); if (!report_timer_.isActive ()) { @@ -169,6 +179,7 @@ public: { if (socket_) { + LOG_LOG_LOCATION (logger_, trace, "disconnecting"); socket_->disconnectFromHost (); } descriptor_timer_.stop (); @@ -180,9 +191,12 @@ public: bool flushing () { - return FLUSH_INTERVAL && !(++flush_counter_ % FLUSH_INTERVAL); + bool flush = FLUSH_INTERVAL && !(++flush_counter_ % FLUSH_INTERVAL); + LOG_LOG_LOCATION (logger_, trace, "flush: " << flush); + return flush; } + logger_type mutable logger_; PSKReporter * self_; Configuration const * config_; QSharedPointer socket_; @@ -267,6 +281,7 @@ void PSKReporter::impl::build_preamble (QDataStream& message) << quint32 (0u) // Export Time (place-holder filled in later) << ++sequence_number_ // Sequence Number << observation_id_; // Observation Domain ID + LOG_LOG_LOCATION (logger_, trace, "#: " << sequence_number_); if (send_descriptors_) { @@ -329,6 +344,7 @@ void PSKReporter::impl::build_preamble (QDataStream& message) // insert Length set_length (out, descriptor); message.writeRawData (descriptor.constData (), descriptor.size ()); + LOG_LOG_LOCATION (logger_, debug, "sent descriptors"); } } @@ -354,11 +370,13 @@ void PSKReporter::impl::build_preamble (QDataStream& message) // insert Length and move to payload set_length (out, data); message.writeRawData (data.constData (), data.size ()); + LOG_LOG_LOCATION (logger_, debug, "sent local information"); } } void PSKReporter::impl::send_report (bool send_residue) { + LOG_LOG_LOCATION (logger_, trace, "sending residue: " << send_residue); if (QAbstractSocket::ConnectedState != socket_->state ()) return; QDataStream message {&payload_, QIODevice::WriteOnly | QIODevice::Append}; @@ -391,9 +409,11 @@ void PSKReporter::impl::send_report (bool send_residue) if (tx_residue_.size ()) { tx_out.writeRawData (tx_residue_.constData (), tx_residue_.size ()); + LOG_LOG_LOCATION (logger_, debug, "sent residue"); tx_residue_.clear (); } + LOG_LOG_LOCATION (logger_, debug, "pending spots: " << spots_.size ()); while (spots_.size () || flush) { auto tx_data_size = tx_data_.size (); @@ -452,6 +472,7 @@ void PSKReporter::impl::send_report (bool send_residue) // Send data to PSK Reporter site socket_->write (payload_); // TODO: handle errors + LOG_LOG_LOCATION (logger_, debug, "sent spots"); flush = false; // break loop message.device ()->seek (0u); payload_.clear (); // Fresh message @@ -462,29 +483,35 @@ void PSKReporter::impl::send_report (bool send_residue) break; } } + LOG_LOG_LOCATION (logger_, debug, "remaining spots: " << spots_.size ()); } } PSKReporter::PSKReporter (Configuration const * config, QString const& program_info) : m_ {this, config, program_info} { + LOG_LOG_LOCATION (m_->logger_, trace, "Started for: " << program_info); } PSKReporter::~PSKReporter () { // m_->send_report (true); // send any pending spots + LOG_LOG_LOCATION (m_->logger_, trace, "Ended"); } void PSKReporter::reconnect () { + LOG_LOG_LOCATION (m_->logger_, trace, ""); m_->reconnect (); } void PSKReporter::setLocalStation (QString const& call, QString const& gridSquare, QString const& antenna) { + LOG_LOG_LOCATION (m_->logger_, trace, "call: " << call << " grid: " << gridSquare << " ant: " << antenna); m_->check_connection (); if (call != m_->rx_call_ || gridSquare != m_->rx_grid_ || antenna != m_->rx_ant_) { + LOG_LOG_LOCATION (m_->logger_, trace, "updating information"); m_->send_receiver_data_ = m_->socket_ && QAbstractSocket::UdpSocket == m_->socket_->socketType () ? 3 : 1; m_->rx_call_ = call; @@ -496,6 +523,7 @@ void PSKReporter::setLocalStation (QString const& call, QString const& gridSquar bool PSKReporter::addRemoteStation (QString const& call, QString const& grid, Radio::Frequency freq , QString const& mode, int snr) { + LOG_LOG_LOCATION (m_->logger_, trace, "call: " << call << " grid: " << grid << " freq: " << freq << " mode: " << mode << " snr: " << snr); m_->check_connection (); if (m_->socket_ && m_->socket_->isValid ()) { @@ -511,6 +539,7 @@ bool PSKReporter::addRemoteStation (QString const& call, QString const& grid, Ra void PSKReporter::sendReport (bool last) { + LOG_LOG_LOCATION (m_->logger_, trace, "last: " << last); m_->check_connection (); if (m_->socket_ && QAbstractSocket::ConnectedState == m_->socket_->state ()) {