Startup and communication bugfixes

- reduce amount of mode switched when starting and loading setups
- improve logging for errors during HIL tests
- fix small USB communication bugs
This commit is contained in:
Jan Käberich 2025-01-06 17:34:46 +01:00
parent 733d0ffbf4
commit ca25969574
14 changed files with 148 additions and 44 deletions

View file

@ -1,4 +1,5 @@
import unittest import unittest
import glob, os
testmodules = [ testmodules = [
'tests.TestUpdate', # Must go first because it updates the connected VNA to the firwmare which should be tested 'tests.TestUpdate', # Must go first because it updates the connected VNA to the firwmare which should be tested
@ -16,6 +17,12 @@ testmodules = [
suite = unittest.TestSuite() suite = unittest.TestSuite()
# Clean up potential error logs from previous test runs
for f in glob.glob("errorlog_*"):
os.remove(f)
for f in glob.glob("packetlog_*"):
os.remove(f)
for t in testmodules: for t in testmodules:
try: try:
# If the module defines a suite() function, call it to get the suite. # If the module defines a suite() function, call it to get the suite.

View file

@ -0,0 +1,22 @@
0.027: [debug] Application start
0.045: [info] Listening on port 19544
0.060: [debug] Activating mode "Vector Network Analyzer"
0.068: [debug] Updated device list, found 1
0.068: [debug] Trying to connect to "208A367A4B42"
0.068: [debug] Attempting to connect to device...
0.075: [info] USB connection established
0.075: [debug] Receive thread started
0.075: [debug] Transmission started (packet type 15 ), queue at 1
0.078: [info] Connected to "208A367A4B42"
0.079: [debug] Transmission started (packet type 26 ), queue at 1
0.082: [debug] No default calibration file set for this device
0.082: [debug] Transmission started (packet type 11 ), queue at 1
0.187: [debug] Transmission started (packet type 2 ), queue at 1
0.533: [debug] Attempting to open calibration from file "LIBRECAL.cal"
0.533: [debug] Associated calibration kit expected in "LIBRECAL.calkit"
0.533: [debug] Opening calkit to file "LIBRECAL.calkit"
0.533: [debug] Parsing of calibration kit failed while opening calibration file: Unable to open file (ignore for calibration format >= 3)
0.899: [debug] Transmission started (packet type 2 ), queue at 1
1.007: [debug] Deactivated mode "Vector Network Analyzer"
1.007: [debug] Transmission started (packet type 20 ), queue at 1
1.050: [debug] Disconnected, receive thread exiting

File diff suppressed because one or more lines are too long

View file

@ -4,43 +4,72 @@ import tests.definitions as defs
import subprocess import subprocess
import time import time
import select import select
import os
from signal import SIGINT from signal import SIGINT
class TestBase(unittest.TestCase): class TestBase(unittest.TestCase):
def setUp(self): def setUp(self):
self.gui = subprocess.Popen([defs.GUI_PATH, '-p', '19544', '--reset-preferences', '--no-gui', '-platform', 'offscreen'], stdout=subprocess.PIPE, stderr=subprocess.STDOUT) f = open("log.txt", "w")
self.gui = subprocess.Popen([defs.GUI_PATH, '-p', '19544', '--reset-preferences', '--no-gui', '-platform', 'offscreen'], stdout=f, stderr=subprocess.STDOUT)
# wait for the SCPI server to become available # wait for the SCPI server to become available
timeout = time.time() + 3; timeout = time.time() + 3;
poll_obj = select.poll() fread = open("log.txt", "r")
poll_obj.register(self.gui.stdout, select.POLLIN)
while True: while True:
poll_result = poll_obj.poll(0) text = fread.read()
if poll_result: if text and "Listening on port 19544" in text:
line = self.gui.stdout.readline().decode().strip() break
if "Listening on port 19544" in line:
break
if time.time() >= timeout: if time.time() >= timeout:
self.tearDown() self.tearDown()
raise AssertionError("Timed out waiting for SCPI server") raise AssertionError("Timed out waiting for SCPI server")
self.vna = libreVNA('localhost', 19544, timeout=4) self.vna = libreVNA('localhost', 19544, timeout=4)
try: try:
self.vna.cmd("*CLS;:DEV:CONN") self.vna.cmd("*CLS")
except Exception as e: except Exception as e:
self.tearDown() self.tearDown()
raise e raise e
if self.vna.query(":DEV:CONN?") == "Not connected": if self.vna.query(":DEV:CONN?") == "Not connected":
self.tearDown() self.tearDown()
raise AssertionError("Not connected") raise AssertionError("Not connected")
def tearDown(self): def tearDown(self):
if hasattr(self._outcome, 'errors'):
# Python 3.4 - 3.10 (These two methods have no side effects)
result = self.defaultTestResult()
self._feedErrorsToResult(result, self._outcome.errors)
else:
# Python 3.11+
result = self._outcome.result
ok = all(test != self for test, text in result.errors + result.failures)
if not ok:
try:
# Try to grab the packet log and save it
packetlog = self.vna.query(":DEV:PACKETLOG?", timeout=5)
f = open("packetlog_"+time.strftime("%Y%m%d%H%M%S.vnalog"), "w")
f.write(packetlog)
f.close()
except:
pass
# make sure the GUI did not crash during the test # make sure the GUI did not crash during the test
self.assertEqual(self.gui.poll(), None) crashed = self.gui.poll() is not None
self.gui.send_signal(SIGINT) self.gui.send_signal(SIGINT)
try: try:
self.gui.wait(timeout = 3) self.gui.wait(timeout = 3)
except subprocess.TimeoutExpired: except subprocess.TimeoutExpired:
self.gui.kill() self.gui.kill()
if ok and not crashed:
# remove log file
os.remove("log.txt")
else:
os.rename("log.txt", "errorlog_"+time.strftime("%Y%m%d%H%M%S.txt"))
if(crashed):
raise Exception("GUI crashed")

View file

@ -29,7 +29,7 @@ CompoundDriver::CompoundDriver()
p.load(d->driverSpecificSettings()); p.load(d->driverSpecificSettings());
} }
specificSettings.push_back(Savable::SettingDescription(&compoundJSONString, "compoundDriver.compoundDeviceJSON", "")); specificSettings.push_back(Savable::SettingDescription(&compoundJSONString, "compoundDriver.compoundDeviceJSON", "{}"));
specificSettings.push_back(Savable::SettingDescription(&captureRawReceiverValues, "compoundDriver.captureRawReceiverValues", false)); specificSettings.push_back(Savable::SettingDescription(&captureRawReceiverValues, "compoundDriver.captureRawReceiverValues", false));
specificSettings.push_back(Savable::SettingDescription(&preservePhase, "compoundDriver.preservePhase", false)); specificSettings.push_back(Savable::SettingDescription(&preservePhase, "compoundDriver.preservePhase", false));
} }
@ -488,6 +488,10 @@ void CompoundDriver::parseCompoundJSON()
{ {
try { try {
configuredDevices.clear(); configuredDevices.clear();
if(compoundJSONString.isEmpty()) {
// empty string will fail JSON parsing. Abort now instead of running into the exception
return;
}
nlohmann::json jc = nlohmann::json::parse(compoundJSONString.toStdString()); nlohmann::json jc = nlohmann::json::parse(compoundJSONString.toStdString());
for(auto j : jc) { for(auto j : jc) {
auto cd = new CompoundDevice(); auto cd = new CompoundDevice();

View file

@ -251,6 +251,11 @@ LibreVNADriver::LibreVNADriver()
} }
return SCPI::getResultName(SCPI::Result::Empty); return SCPI::getResultName(SCPI::Result::Empty);
}, nullptr)); }, nullptr));
specificSCPIcommands.push_back(new SCPICommand("DEVice:PACKETLOG", nullptr, [=](QStringList) -> QString {
auto &log = DevicePacketLog::getInstance();
return QString::fromStdString(log.toJSON().dump());
}));
} }
std::set<DeviceDriver::Flag> LibreVNADriver::getFlags() std::set<DeviceDriver::Flag> LibreVNADriver::getFlags()
@ -407,6 +412,7 @@ QStringList LibreVNADriver::availableVNAMeasurements()
bool LibreVNADriver::setVNA(const DeviceDriver::VNASettings &s, std::function<void (bool)> cb) bool LibreVNADriver::setVNA(const DeviceDriver::VNASettings &s, std::function<void (bool)> cb)
{ {
if(!supports(Feature::VNA)) { if(!supports(Feature::VNA)) {
qDebug() << "VNA does not support features \"VNA\" (has the DeviceInfo been received?)";
return false; return false;
} }
if(s.excitedPorts.size() == 0) { if(s.excitedPorts.size() == 0) {

View file

@ -4,6 +4,7 @@
#include "devicepacketlog.h" #include "devicepacketlog.h"
#include <QTimer> #include <QTimer>
#include <QThread>
using namespace std; using namespace std;
@ -166,9 +167,9 @@ void LibreVNAUSBDriver::ReceivedData()
uint16_t handled_len; uint16_t handled_len;
// qDebug() << "Received data"; // qDebug() << "Received data";
do { do {
// qDebug() << "Decoding" << dataBuffer->getReceived() << "Bytes"; // qDebug() << "Decoding" << dataBuffer->getReceived() << "Bytes";
handled_len = Protocol::DecodeBuffer(dataBuffer->getBuffer(), dataBuffer->getReceived(), &packet); handled_len = Protocol::DecodeBuffer(dataBuffer->getBuffer(), dataBuffer->getReceived(), &packet);
// qDebug() << "Handled" << handled_len << "Bytes, type:" << (int) packet.type; // qDebug() << "Handled" << handled_len << "Bytes, type:" << (int) packet.type;
if(handled_len > 0) { if(handled_len > 0) {
auto &log = DevicePacketLog::getInstance(); auto &log = DevicePacketLog::getInstance();
if(packet.type != Protocol::PacketType::None) { if(packet.type != Protocol::PacketType::None) {
@ -185,6 +186,8 @@ void LibreVNAUSBDriver::ReceivedData()
case Protocol::PacketType::Nack: case Protocol::PacketType::Nack:
emit receivedAnswer(TransmissionResult::Nack); emit receivedAnswer(TransmissionResult::Nack);
break; break;
case Protocol::PacketType::None:
break;
default: default:
// pass on to LibreVNADriver class // pass on to LibreVNADriver class
emit receivedPacket(packet); emit receivedPacket(packet);
@ -220,12 +223,12 @@ void LibreVNAUSBDriver::transmissionFinished(LibreVNADriver::TransmissionResult
{ {
lock_guard<mutex> lock(transmissionMutex); lock_guard<mutex> lock(transmissionMutex);
// remove transmitted packet // remove transmitted packet
// qDebug() << "Transmission finsished (" << result << "), queue at " << transmissionQueue.size() << " Outstanding ACKs:"<<outstandingAckCount;
if(transmissionQueue.empty()) { if(transmissionQueue.empty()) {
qWarning() << "transmissionFinished with empty transmission queue, stray Ack? Result:" << result; qWarning() << "transmissionFinished with empty transmission queue, stray Ack? Result:" << result;
return; return;
} }
auto t = transmissionQueue.dequeue(); auto t = transmissionQueue.dequeue();
// qDebug() << "Transmission finsished (packet type" << (int) t.packet.type <<",result" << result << "), queue at " << transmissionQueue.size();
if(result == TransmissionResult::Timeout) { if(result == TransmissionResult::Timeout) {
qWarning() << "transmissionFinished with timeout, packettype:" << (int) t.packet.type << "Device:" << serial; qWarning() << "transmissionFinished with timeout, packettype:" << (int) t.packet.type << "Device:" << serial;
} }
@ -374,6 +377,6 @@ bool LibreVNAUSBDriver::startNextTransmission()
return false; return false;
} }
transmissionTimer.start(t.timeout); transmissionTimer.start(t.timeout);
// qDebug() << "Transmission started, queue at " << transmissionQueue.size(); qDebug() << "Transmission started (packet type" << (int) t.packet.type << "), queue at " << transmissionQueue.size();
return true; return true;
} }

View file

@ -340,10 +340,10 @@ SpectrumAnalyzer::SpectrumAnalyzer(AppWindow *window, QString name)
void SpectrumAnalyzer::deactivate() void SpectrumAnalyzer::deactivate()
{ {
setOperationPending(false);
StoreSweepSettings(); StoreSweepSettings();
configurationTimer.stop(); configurationTimer.stop();
Mode::deactivate(); Mode::deactivate();
setOperationPending(false);
} }
void SpectrumAnalyzer::initializeDevice() void SpectrumAnalyzer::initializeDevice()
@ -588,7 +588,11 @@ void SpectrumAnalyzer::NewDatapoint(DeviceDriver::SAMeasurement m)
void SpectrumAnalyzer::SettingsChanged() void SpectrumAnalyzer::SettingsChanged()
{ {
if(window->getDevice()) { if(!running) {
// not running, no need for any communication
return;
}
if(isActive && window->getDevice()) {
setOperationPending(true); setOperationPending(true);
} }
configurationTimer.start(100); configurationTimer.start(100);
@ -695,10 +699,15 @@ void SpectrumAnalyzer::SetSingleSweep(bool single)
{ {
if(singleSweep != single) { if(singleSweep != single) {
singleSweep = single; singleSweep = single;
if(single) {
Run();
}
emit singleSweepChanged(single); emit singleSweepChanged(single);
} } else {
if(single) { // if already set to single, a second single command triggers a new sweep
Run(); if(single && !running) {
Run();
}
} }
} }
@ -734,7 +743,9 @@ void SpectrumAnalyzer::SetAveraging(unsigned int averages)
average.setAverages(averages); average.setAverages(averages);
emit averagingChanged(averages); emit averagingChanged(averages);
UpdateAverageCount(); UpdateAverageCount();
setOperationPending(!average.settled()); if(isActive && window->getDevice()) {
setOperationPending(!average.settled());
}
} }
void SpectrumAnalyzer::SetTGEnabled(bool enabled) void SpectrumAnalyzer::SetTGEnabled(bool enabled)
@ -871,6 +882,7 @@ void SpectrumAnalyzer::Stop()
{ {
running = false; running = false;
ConfigureDevice(); ConfigureDevice();
setOperationPending(false);
} }
void SpectrumAnalyzer::ConfigureDevice() void SpectrumAnalyzer::ConfigureDevice()
@ -920,9 +932,6 @@ void SpectrumAnalyzer::ConfigureDevice()
void SpectrumAnalyzer::ResetLiveTraces() void SpectrumAnalyzer::ResetLiveTraces()
{ {
if(window->getDevice()) {
setOperationPending(true);
}
average.reset(DeviceDriver::SApoints()); average.reset(DeviceDriver::SApoints());
traceModel.clearLiveData(); traceModel.clearLiveData();
UpdateAverageCount(); UpdateAverageCount();

View file

@ -745,10 +745,10 @@ QString VNA::getCalToolTip()
void VNA::deactivate() void VNA::deactivate()
{ {
setOperationPending(false);
StoreSweepSettings(); StoreSweepSettings();
configurationTimer.stop(); configurationTimer.stop();
Mode::deactivate(); Mode::deactivate();
setOperationPending(false);
} }
static void SetComboBoxItemEnabled(QComboBox * comboBox, int index, bool enabled) static void SetComboBoxItemEnabled(QComboBox * comboBox, int index, bool enabled)
@ -939,9 +939,8 @@ void VNA::NewDatapoint(DeviceDriver::VNAMeasurement m)
} }
// Calculate sweep time // Calculate sweep time
if(m.pointNum == 0) { if(m.pointNum == 0 && lastPoint > 0) {
// new sweep started // new sweep started
static auto lastStart = QDateTime::currentDateTimeUtc();
auto now = QDateTime::currentDateTimeUtc(); auto now = QDateTime::currentDateTimeUtc();
auto sweepTime = lastStart.msecsTo(now); auto sweepTime = lastStart.msecsTo(now);
lastStart = now; lastStart = now;
@ -1042,7 +1041,6 @@ void VNA::NewDatapoint(DeviceDriver::VNAMeasurement m)
markerModel->updateMarkers(); markerModel->updateMarkers();
} }
static unsigned int lastPoint = 0;
if(m_avg.pointNum > 0 && m_avg.pointNum != lastPoint + 1) { if(m_avg.pointNum > 0 && m_avg.pointNum != lastPoint + 1) {
qWarning() << "Got point" << m_avg.pointNum << "but last received point was" << lastPoint << "("<<(m_avg.pointNum-lastPoint-1)<<"missed points)"; qWarning() << "Got point" << m_avg.pointNum << "but last received point was" << lastPoint << "("<<(m_avg.pointNum-lastPoint-1)<<"missed points)";
} }
@ -1065,7 +1063,11 @@ void VNA::UpdateAverageCount()
void VNA::SettingsChanged(bool resetTraces, int delay) void VNA::SettingsChanged(bool resetTraces, int delay)
{ {
if(window->getDevice()) { if(!running) {
// not running, no need for any communication
return;
}
if(isActive && window->getDevice()) {
setOperationPending(true); setOperationPending(true);
} }
configurationTimer.start(delay); configurationTimer.start(delay);
@ -1317,7 +1319,9 @@ void VNA::SetAveraging(unsigned int averages)
average.setAverages(averages); average.setAverages(averages);
emit averagingChanged(averages); emit averagingChanged(averages);
UpdateAverageCount(); UpdateAverageCount();
setOperationPending(!average.settled()); if(isActive && window->getDevice()) {
setOperationPending(!average.settled());
}
} }
void VNA::ExcitationRequired() void VNA::ExcitationRequired()
@ -1880,10 +1884,15 @@ void VNA::SetSingleSweep(bool single)
{ {
if(singleSweep != single) { if(singleSweep != single) {
singleSweep = single; singleSweep = single;
if(single) {
Run();
}
emit singleSweepChanged(single); emit singleSweepChanged(single);
} } else {
if(single) { // if already set to single, a second single command triggers a new sweep
Run(); if(single && !running) {
Run();
}
} }
} }
@ -1897,6 +1906,7 @@ void VNA::Stop()
{ {
running = false; running = false;
ConfigureDevice(false); ConfigureDevice(false);
setOperationPending(false);
} }
void VNA::ConfigureDevice(bool resetTraces, std::function<void(bool)> cb) void VNA::ConfigureDevice(bool resetTraces, std::function<void(bool)> cb)
@ -1976,6 +1986,8 @@ void VNA::ConfigureDevice(bool resetTraces, std::function<void(bool)> cb)
cb(res); cb(res);
} }
changingSettings = false; changingSettings = false;
lastStart = QDateTime::currentDateTimeUtc();
lastPoint = -1;
}); });
emit sweepStarted(); emit sweepStarted();
} else { } else {
@ -2004,7 +2016,7 @@ void VNA::ResetLiveTraces()
traceModel.clearLiveData(); traceModel.clearLiveData();
UpdateAverageCount(); UpdateAverageCount();
UpdateCalWidget(); UpdateCalWidget();
if(window->getDevice()) { if(isActive && window->getDevice()) {
setOperationPending(true); setOperationPending(true);
} }
} }

View file

@ -198,6 +198,10 @@ private:
QList<QAction*> importActions; QList<QAction*> importActions;
QList<QAction*> exportActions; QList<QAction*> exportActions;
// Statistics for detecting missing points and sweep time
QDateTime lastStart;
int lastPoint;
signals: signals:
void deviceInitialized(); void deviceInitialized();
void dataChanged(); void dataChanged();

View file

@ -31,10 +31,6 @@ int ModeHandler::addMode(Mode *mode)
modes.push_back(mode); modes.push_back(mode);
currentModeIndex = int(modes.size()) - 1; currentModeIndex = int(modes.size()) - 1;
connect(mode, &Mode::statusbarMessage, this, &ModeHandler::setStatusBarMessageChanged); connect(mode, &Mode::statusbarMessage, this, &ModeHandler::setStatusBarMessageChanged);
auto m = getMode(currentModeIndex);
activate(m);
emit ModeCreated(currentModeIndex); emit ModeCreated(currentModeIndex);
return (currentModeIndex); return (currentModeIndex);
} }
@ -166,7 +162,12 @@ void ModeHandler::closeMode(int index)
void ModeHandler::closeModes() void ModeHandler::closeModes()
{ {
while(modes.size() > 0) { while(modes.size() > 0) {
closeMode(0); // skip active mode unless it is the last remaining mode
if(activeMode == modes[0] && modes.size() > 1) {
closeMode(1);
} else {
closeMode(0);
}
} }
} }

View file

@ -70,7 +70,8 @@ void ModeWindow::SetupUi()
InformationBox::ShowError("Name collision", "Unable to create tab, " \ InformationBox::ShowError("Name collision", "Unable to create tab, " \
"no duplicate names allowed"); "no duplicate names allowed");
} else { } else {
handler->createMode(text, type); auto index = handler->createMode(text, type);
handler->setCurrentIndex(index);
} }
} }
}; };
@ -157,7 +158,6 @@ void ModeWindow::ModeCreated(int modeIndex)
tabBar->insertTab(modeIndex, name); tabBar->insertTab(modeIndex, name);
tabBar->blockSignals(false); tabBar->blockSignals(false);
tabBar->setMovable(true); tabBar->setMovable(true);
tabBar->setCurrentIndex(modeIndex);
} }
} }

View file

@ -369,8 +369,13 @@ void SCPINode::setOperationPending(bool pending)
while(root->parent) { while(root->parent) {
root = root->parent; root = root->parent;
} }
auto scpi = static_cast<SCPI*>(root); auto scpi = dynamic_cast<SCPI*>(root);
scpi->someOperationCompleted(); if(!scpi) {
// dynamic cast failed, this is not actually a root node. The SCPI node likely
// has no valid parent configured
} else {
scpi->someOperationCompleted();
}
} }
} }
} }

View file

@ -269,6 +269,7 @@ bool usb_transmit(const uint8_t *data, uint16_t length) {
} }
bool ret = true; bool ret = true;
if(!data_transmission_active) { if(!data_transmission_active) {
last_transmission = HAL_GetTick();
ret = trigger_next_fifo_transmission(); ret = trigger_next_fifo_transmission();
} }
__enable_irq(); __enable_irq();