Add rate_ctr support to store/retrieve SDR errors through VTY

Introduce a unified implementation-agnostic interface for radioDevice to
signal SDR error counters to upper layers and manage them.
This patch only implements counters for osmo-trx-lms (other devices will
show all counters unchanged during time).

Sample use through VTY:
"""
OsmoTRX> show rate-counters
osmo-trx statistics 0:
   device:rx_underruns:          0 (0/s 0/m 0/h 0/d) Number of Rx underruns
    device:rx_overruns:          0 (0/s 0/m 0/h 0/d) Number of Rx overruns
   device:tx_underruns:          0 (0/s 0/m 0/h 0/d) Number of Tx underruns
 device:rx_drop_events:          4 (0/s 2/m 3/h 0/d) Number of times Rx samples were dropped by HW
device:rx_drop_samples:        513 (0/s 196/m 425/h 0/d) Number of Rx samples dropped by HW
"""

Change-Id: I78b158141697e5714d04db8b9ccc96f31f34f439
This commit is contained in:
Pau Espin 2019-05-24 16:54:19 +02:00
parent 76a5013c91
commit 4456b6f132
8 changed files with 262 additions and 37 deletions

View File

@ -35,6 +35,7 @@ libcommon_la_SOURCES = \
Timeval.cpp \
Logger.cpp \
Utils.cpp \
trx_rate_ctr.cpp \
trx_vty.c \
debug.c
libcommon_la_LIBADD = $(LIBOSMOCORE_LIBS) $(LIBOSMOCTRL_LIBS) $(LIBOSMOVTY_LIBS)
@ -50,6 +51,7 @@ noinst_HEADERS = \
Vector.h \
Logger.h \
Utils.h \
trx_rate_ctr.h \
trx_vty.h \
debug.h \
osmo_signal.h \

View File

@ -27,9 +27,28 @@
/* Signalling subsystems */
enum signal_subsystems {
SS_TRANSC,
SS_DEVICE,
};
/* SS_TRANSC signals */
enum SS_TRANSC {
S_TRANSC_STOP_REQUIRED, /* Transceiver fatal error, it should be stopped */
};
/* SS_DEVICE signals */
enum SS_DEVICE {
/* Device internal counters changed. Counters are provided as cb data
(struct device_counters). Must be sent with PTHREAD_CANCEL_DISABLE
to avoid deadlocks in case osmo-trx process is asked to exit. */
S_DEVICE_COUNTER_CHANGE,
};
/* signal cb for signal <SS_DEVICE,S_DEVICE_COUNTER_CHANGE> */
struct device_counters {
size_t chan;
unsigned int rx_underruns;
unsigned int rx_overruns;
unsigned int tx_underruns;
unsigned int rx_dropped_events;
unsigned int rx_dropped_samples;
};

180
CommonLibs/trx_rate_ctr.cpp Normal file
View File

@ -0,0 +1,180 @@
/*
* Copyright (C) 2019 sysmocom - s.f.m.c. GmbH
* All Rights Reserved
*
* Author: Pau Espin Pedrol <pespin@sysmocom.de>
*
* This program is free software; you can redistribute it and/or modify
* it under the terms of the GNU General Public License as published by
* the Free Software Foundation; either version 2 of the License, or
* (at your option) any later version.
*
* This program is distributed in the hope that it will be useful,
* but WITHOUT ANY WARRANTY; without even the implied warranty of
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
* GNU General Public License for more details.
*
* You should have received a copy of the GNU General Public License
* along with this program. If not, see <http://www.gnu.org/licenses/>.
*
*/
/*
* rate_ctr API uses several osmocom select loop features, and as a result,
* calls to it must be done through the main thread (the one running the osmocom
* loop in osmo-trx).
* Since read/write from/to SDR is done in separate threads (even read and write
* each use a different thread), we must use some sort of message passing system
* between main thread feeding rate_ctr structures and the Rx/Tx threads
* generating the events.
* The idea is that upon read/write issues, lower layers (SDR APIs) provide us with
* underrun/overrun/droppedPackets information, and in that case we pass that up
* the stack through signal <SS_DEVICE,S_DEVICE_COUNTER_CHANGE> with signal_cb
* being a pointer to a "struct device_counters" structure, which contains
* device (implementation agnostic) statful counters for different kind of
* statistics.
* That signal is processed here in device_sig_cb, where a copy of the "struct
* device_counters" structure is held and the main thread is instructed through
* a timerfd to update rate_ctr APIs against this copy. All this is done inside
* a mutex to avoid different race conditons (between Rx andTx threads, and
* between Rx/Tx and main thread). For the same reason, callers of signal
* <SS_DEVICE,S_DEVICE_COUNTER_CHANGE> (device_sig_cb), that is Rx/Tx threads,
* must do so with PTHREAD_CANCEL_DISABLE, in order to avoid possible deadlocks
* in case the main thread decides to cancel other threads due to a shutdown
* operation (fi SIGKILL received)
*/
#include <string.h>
#include <stdint.h>
#include <inttypes.h>
#include <netinet/in.h>
#include <arpa/inet.h>
extern "C" {
#include <osmocom/core/talloc.h>
#include <osmocom/core/utils.h>
#include <osmocom/core/rate_ctr.h>
#include <osmocom/core/select.h>
#include <osmocom/core/stats.h>
#include "osmo_signal.h"
#include "trx_vty.h"
#include "trx_rate_ctr.h"
}
#include "Threads.h"
#include "Logger.h"
/* Used in ctrs_pending, when set it means that channel slot contains unused
(non-pending) counter data */
#define PENDING_CHAN_NONE SIZE_MAX
static struct rate_ctr_group** rate_ctrs;
static struct device_counters* ctrs_pending;
static size_t chan_len;
static struct osmo_fd rate_ctr_timerfd;
static Mutex rate_ctr_mutex;
enum {
TRX_CTR_RX_UNDERRUNS,
TRX_CTR_RX_OVERRUNS,
TRX_CTR_TX_UNDERRUNS,
TRX_CTR_RX_DROP_EV,
TRX_CTR_RX_DROP_SMPL,
};
static const struct rate_ctr_desc trx_chan_ctr_desc[] = {
[TRX_CTR_RX_UNDERRUNS] = { "device:rx_underruns", "Number of Rx underruns" },
[TRX_CTR_RX_OVERRUNS] = { "device:rx_overruns", "Number of Rx overruns" },
[TRX_CTR_TX_UNDERRUNS] = { "device:tx_underruns", "Number of Tx underruns" },
[TRX_CTR_RX_DROP_EV] = { "device:rx_drop_events", "Number of times Rx samples were dropped by HW" },
[TRX_CTR_RX_DROP_SMPL] = { "device:rx_drop_samples", "Number of Rx samples dropped by HW" },
};
static const struct rate_ctr_group_desc trx_chan_ctr_group_desc = {
.group_name_prefix = "trx:chan",
.group_description = "osmo-trx statistics",
.class_id = OSMO_STATS_CLASS_GLOBAL,
.num_ctr = ARRAY_SIZE(trx_chan_ctr_desc),
.ctr_desc = trx_chan_ctr_desc,
};
static int rate_ctr_timerfd_cb(struct osmo_fd *ofd, unsigned int what) {
size_t chan;
struct rate_ctr *ctr;
LOGC(DMAIN, NOTICE) << "Main thread is updating counters";
rate_ctr_mutex.lock();
for (chan = 0; chan < chan_len; chan++) {
if (ctrs_pending[chan].chan == PENDING_CHAN_NONE)
continue;
LOGCHAN(chan, DMAIN, INFO) << "rate_ctr update";
ctr = &rate_ctrs[chan]->ctr[TRX_CTR_RX_UNDERRUNS];
rate_ctr_add(ctr, ctrs_pending[chan].rx_underruns - ctr->current);
ctr = &rate_ctrs[chan]->ctr[TRX_CTR_RX_OVERRUNS];
rate_ctr_add(ctr, ctrs_pending[chan].rx_overruns - ctr->current);
ctr = &rate_ctrs[chan]->ctr[TRX_CTR_TX_UNDERRUNS];
rate_ctr_add(ctr, ctrs_pending[chan].tx_underruns - ctr->current);
ctr = &rate_ctrs[chan]->ctr[TRX_CTR_RX_DROP_EV];
rate_ctr_add(ctr, ctrs_pending[chan].rx_dropped_events - ctr->current);
ctr = &rate_ctrs[chan]->ctr[TRX_CTR_RX_DROP_SMPL];
rate_ctr_add(ctr, ctrs_pending[chan].rx_dropped_samples - ctr->current);
/* Mark as done */
ctrs_pending[chan].chan = PENDING_CHAN_NONE;
}
if (osmo_timerfd_disable(&rate_ctr_timerfd) < 0)
LOGC(DMAIN, ERROR) << "Failed to disable timerfd";
rate_ctr_mutex.unlock();
return 0;
}
/* Callback function to be called every time we receive a signal from DEVICE */
static int device_sig_cb(unsigned int subsys, unsigned int signal,
void *handler_data, void *signal_data)
{
struct device_counters *ctr;
/* Delay sched around 20 ms, in case we receive several calls from several
* channels batched */
struct timespec next_sched = {.tv_sec = 0, .tv_nsec = 20*1000*1000};
/* no automatic re-trigger */
struct timespec intv_sched = {.tv_sec = 0, .tv_nsec = 0};
switch (signal) {
case S_DEVICE_COUNTER_CHANGE:
ctr = (struct device_counters *)signal_data;
LOGCHAN(ctr->chan, DMAIN, NOTICE) << "Received counter change from radioDevice";
rate_ctr_mutex.lock();
ctrs_pending[ctr->chan] = *ctr;
if (osmo_timerfd_schedule(&rate_ctr_timerfd, &next_sched, &intv_sched) < 0) {
LOGC(DMAIN, ERROR) << "Failed to schedule timerfd: " << errno << " = "<< strerror(errno);
}
rate_ctr_mutex.unlock();
break;
default:
break;
}
return 0;
}
/* Init rate_ctr subsystem. Expected to be called during process start by main thread */
void trx_rate_ctr_init(void *ctx, struct trx_ctx* trx_ctx)
{
size_t i;
chan_len = trx_ctx->cfg.num_chans;
ctrs_pending = (struct device_counters*) talloc_zero_size(ctx, chan_len * sizeof(struct device_counters));
rate_ctrs = (struct rate_ctr_group**) talloc_zero_size(ctx, chan_len * sizeof(struct rate_ctr_group*));
for (i = 0; i < chan_len; i++) {
ctrs_pending[i].chan = PENDING_CHAN_NONE;
rate_ctrs[i] = rate_ctr_group_alloc(ctx, &trx_chan_ctr_group_desc, i);
if (!rate_ctrs[i]) {
LOGCHAN(i, DMAIN, ERROR) << "Failed to allocate rate ctr";
exit(1);
}
}
rate_ctr_timerfd.fd = -1;
if (osmo_timerfd_setup(&rate_ctr_timerfd, rate_ctr_timerfd_cb, NULL) < 0) {
LOGC(DMAIN, ERROR) << "Failed to setup timerfd";
exit(1);
}
osmo_signal_register_handler(SS_DEVICE, device_sig_cb, NULL);
}

View File

@ -0,0 +1,4 @@
#pragma once
struct trx_ctx;
void trx_rate_ctr_init(void *ctx, struct trx_ctx* trx_ctx);

View File

@ -23,6 +23,7 @@
extern "C" {
#include "config_defs.h"
#include "osmo_signal.h"
}
#ifdef HAVE_CONFIG_H
@ -168,13 +169,20 @@ class RadioDevice {
size_t chans;
double lo_offset;
std::vector<std::string> tx_paths, rx_paths;
std::vector<struct device_counters> m_ctr;
RadioDevice(size_t tx_sps, size_t rx_sps, InterfaceType type, size_t chans, double offset,
const std::vector<std::string>& tx_paths,
const std::vector<std::string>& rx_paths):
tx_sps(tx_sps), rx_sps(rx_sps), iface(type), chans(chans), lo_offset(offset),
tx_paths(tx_paths), rx_paths(rx_paths)
{ }
{
m_ctr.resize(chans);
for (size_t i = 0; i < chans; i++) {
memset(&m_ctr[i], 0, sizeof(m_ctr[i]));
m_ctr[i].chan = i;
}
}
bool set_antennas() {
unsigned int i;

View File

@ -25,7 +25,10 @@
#include <lime/LimeSuite.h>
extern "C" {
#include "osmo_signal.h"
#include <osmocom/core/utils.h>
}
#ifdef HAVE_CONFIG_H
#include "config.h"
@ -53,11 +56,6 @@ LMSDevice::LMSDevice(size_t tx_sps, size_t rx_sps, InterfaceType iface, size_t c
m_lms_stream_rx.resize(chans);
m_lms_stream_tx.resize(chans);
m_last_rx_underruns.resize(chans, 0);
m_last_rx_overruns.resize(chans, 0);
m_last_rx_dropped.resize(chans, 0);
m_last_tx_underruns.resize(chans, 0);
rx_buffers.resize(chans);
}
@ -580,32 +578,45 @@ GSM::Time LMSDevice::minLatency() {
void LMSDevice::update_stream_stats(size_t chan, bool * underrun, bool * overrun)
{
lms_stream_status_t status;
if (LMS_GetStreamStatus(&m_lms_stream_rx[chan], &status) == 0) {
if (status.underrun > m_last_rx_underruns[chan]) {
*underrun = true;
LOGCHAN(chan, DDEV, ERROR) << "recv Underrun! ("
<< m_last_rx_underruns[chan] << " -> "
<< status.underrun << ")";
}
m_last_rx_underruns[chan] = status.underrun;
bool changed = false;
if (status.overrun > m_last_rx_overruns[chan]) {
*overrun = true;
LOGCHAN(chan, DDEV, ERROR) << "recv Overrun! ("
<< m_last_rx_overruns[chan] << " -> "
<< status.overrun << ")";
}
m_last_rx_overruns[chan] = status.overrun;
if (status.droppedPackets) {
LOGCHAN(chan, DDEV, ERROR) << "recv Dropped packets by HW! ("
<< m_last_rx_dropped[chan] << " -> "
<< m_last_rx_dropped[chan] +
status.droppedPackets
<< ")";
}
m_last_rx_dropped[chan] += status.droppedPackets;
if (LMS_GetStreamStatus(&m_lms_stream_rx[chan], &status) != 0) {
LOGCHAN(chan, DDEV, ERROR) << "LMS_GetStreamStatus failed";
return;
}
if (status.underrun > m_ctr[chan].rx_underruns) {
changed = true;
*underrun = true;
LOGCHAN(chan, DDEV, ERROR) << "recv Underrun! ("
<< m_ctr[chan].rx_underruns << " -> "
<< status.underrun << ")";
}
m_ctr[chan].rx_underruns = status.underrun;
if (status.overrun > m_ctr[chan].rx_overruns) {
changed = true;
*overrun = true;
LOGCHAN(chan, DDEV, ERROR) << "recv Overrun! ("
<< m_ctr[chan].rx_overruns << " -> "
<< status.overrun << ")";
}
m_ctr[chan].rx_overruns = status.overrun;
if (status.droppedPackets) {
changed = true;
LOGCHAN(chan, DDEV, ERROR) << "recv Dropped packets by HW! ("
<< m_ctr[chan].rx_dropped_samples << " -> "
<< m_ctr[chan].rx_dropped_samples +
status.droppedPackets
<< ")";
m_ctr[chan].rx_dropped_events++;
}
m_ctr[chan].rx_dropped_samples += status.droppedPackets;
if (changed)
osmo_signal_dispatch(SS_DEVICE, S_DEVICE_COUNTER_CHANGE, &m_ctr[chan]);
}
// NOTE: Assumes sequential reads
@ -719,9 +730,12 @@ int LMSDevice::writeSamples(std::vector < short *>&bufs, int len,
}
if (LMS_GetStreamStatus(&m_lms_stream_tx[i], &status) == 0) {
if (status.underrun > m_last_tx_underruns[i])
if (status.underrun > m_ctr[i].tx_underruns) {
*underrun = true;
m_last_tx_underruns[i] = status.underrun;
m_ctr[i].tx_underruns = status.underrun;
osmo_signal_dispatch(SS_DEVICE, S_DEVICE_COUNTER_CHANGE, &m_ctr[i]);
}
}
thread_enable_cancel(true);
}

View File

@ -49,11 +49,6 @@ private:
std::vector<lms_stream_t> m_lms_stream_rx;
std::vector<lms_stream_t> m_lms_stream_tx;
std::vector<uint32_t> m_last_rx_underruns;
std::vector<uint32_t> m_last_rx_overruns;
std::vector<uint32_t> m_last_rx_dropped;
std::vector<uint32_t> m_last_tx_underruns;
std::vector<smpl_buf *> rx_buffers;
double actualSampleRate; ///< the actual USRP sampling rate

View File

@ -59,6 +59,7 @@ extern "C" {
#include "trx_vty.h"
#include "debug.h"
#include "osmo_signal.h"
#include "trx_rate_ctr.h"
}
#define DEFAULT_CONFIG_FILE "osmo-trx.cfg"
@ -626,6 +627,8 @@ int main(int argc, char *argv[])
return EXIT_FAILURE;
}
trx_rate_ctr_init(tall_trx_ctx, g_trx_ctx);
srandom(time(NULL));
if(trx_start(g_trx_ctx) < 0)