AllSpice/ThunderScope
19
Fork 0
Files Issues 7 Design Reviews Releases Activity

better logging with TRACE, DEBUG, and FATAL #160

Merged
AlexVdberg merged 2 commits from dev-logger into master 2021-03-15 16:37:01 +00:00
Conversation 0 Commits 2 Files Changed 9 +113 -94
9 changed files with 113 additions and 94 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

7
Software/waveview/scope_link/include/logger.hpp
View File

@ -14,11 +14,14 @@
#include <boost/log/trivial.hpp>
#include <boost/log/utility/setup.hpp>
#define TRACE BOOST_LOG_SEV(my_logger::get(), boost::log::trivial::trace)
#define DEBUG BOOST_LOG_SEV(my_logger::get(), boost::log::trivial::debug)
#define INFO BOOST_LOG_SEV(my_logger::get(), boost::log::trivial::info)
#define WARN BOOST_LOG_SEV(my_logger::get(), boost::log::trivial::warning)
#define ERROR BOOST_LOG_SEV(my_logger::get(), boost::log::trivial::error)
#define FATAL BOOST_LOG_SEV(my_logger::get(), boost::log::trivial::fatal)
#define SYS_LOGFILE "/var/log/example.log"
#define SYS_LOGFILE "/var/log/example.log"
//Narrow-char thread-safe logger.
typedef boost::log::sources::severity_logger_mt<boost::log::trivial::severity_level> logger_t;
@ -26,4 +29,6 @@ typedef boost::log::sources::severity_logger_mt<boost::log::trivial::severity_le
//declares a global logger with a custom initialization
BOOST_LOG_GLOBAL_LOGGER(my_logger, logger_t)
std::string convert_int(int n);
#endif // logger_h

2
Software/waveview/scope_link/src/EVTester.cpp
View File

@ -52,7 +52,7 @@ bool loadFromFile ( char* filename, boost::lockfree::queue<buffer*, boost::lockf
tmpBufPos++;
if (tmpBufPos == BUFFER_SIZE) {
INFO << "Adding buffer to queue from file";
DEBUG << "Adding buffer to queue from file";
// Buffer is now full push it
outputQ->push(tempBuffer);

56
Software/waveview/scope_link/src/bridge.cpp
View File

@ -29,12 +29,13 @@ inline void FreePacket(EVPacket* packet) {
* None
******************************************************************************/
void PrintPacket(EVPacket* packet) {
printf("PacketID_HEX: %X, Command: %d, DataSize: %d, Data: ",
packet->packetID, packet->command,packet->dataSize);
std::string dbgMsg = "PacketID_HEX: " + convert_int(packet->packetID);
dbgMsg += ", Command: " + std::to_string(packet->command);
dbgMsg += ", DataSize: " + std::to_string(packet->dataSize) + ", Data: ";
for(unsigned i = 0; i < packet->dataSize; i++) {
printf("%X ",packet->data[i]);
dbgMsg += convert_int(packet->data[i]) + " ";
}
printf("\n");
INFO << dbgMsg;
}
/*******************************************************************************
@ -99,14 +100,14 @@ txQueue(txQueue)
* None
******************************************************************************/
Bridge::~Bridge() {
INFO << "Destroying bridge";
DEBUG << "Destroying bridge";
if (rx_run.load() == true) {
RxStop();
}
if (tx_run.load() == true) {
TxStop();
}
INFO << "Bridge destroyed";
DEBUG << "Bridge destroyed";
}
/*******************************************************************************
@ -137,7 +138,7 @@ int Bridge::makeConnection(int targetSocket ) {
return -1;
}
INFO << "targetSocket: listening for clients, waiting to aceept....";
INFO << "targetSocket: listening for clients, waiting to accept....";
// accept the first client to connect
// No need to save it's fd since we will never write to it
struct sockaddr_un address;
@ -176,7 +177,7 @@ void Bridge::TxJob() {
return;
}
ConnectNamedPipe(tx_hPipe, NULL);
INFO << "tx_pipe: client connected";
DEBUG << "tx_pipe: client connected";
#else
client_tx_sock = makeConnection(tx_sock);
if (client_tx_sock < 0) {
@ -230,7 +231,7 @@ void Bridge::RxJob() {
return;
}
ConnectNamedPipe(rx_hPipe, NULL);
INFO << "rx_pipe: client connected";
DEBUG << "rx_pipe: client connected";
#else
client_rx_sock = makeConnection(rx_sock);
if (client_rx_sock < 0) {
@ -268,7 +269,7 @@ void Bridge::RxJob() {
&& endPacketCheck[1] == END_PACKET_PACKETID
&& endPacketCheck[2] == END_PACKET_DATA_SIZE) {
INFO << "END PACKET Recieved, Jumping Out Of RX Job";
DEBUG << "END PACKET Recieved, Jumping Out Of RX Job";
rx_run.store(false);
continue;
}
@ -292,7 +293,7 @@ void Bridge::RxJob() {
std::this_thread::sleep_for(std::chrono::milliseconds(500));
continue;
} else {
INFO << "rx_pipe data_read: Error: " << GetLastError();
ERROR << "rx_pipe data_read: Error: " << GetLastError();
break;
}
}
@ -321,10 +322,11 @@ void Bridge::RxJob() {
}
#endif
//process whatever is sent (for now just print it)
printf("Packet Size: %d, Packet Info:\n",(int)packet_size);
for(int i = 0; i < (int)packet_size; i++)
printf("%X ",rxBuff[i]);
printf("\n");
std::string dbgMsg = "Packet Size: " + std::to_string(packet_size) + " Packet Info: ";
for(int i = 0; i < (int)packet_size; i++) {
dbgMsg += convert_int(rxBuff[i]) + " ";
}
INFO << dbgMsg;
// TODO: you can just cast it as the struct and access things that way
uint16_t* rxBuff16 = (uint16_t*) rxBuff;
@ -374,11 +376,11 @@ int Bridge::TxStart() {
if (err) {
return err;
}
INFO << "Initialized Tx Bridge";
DEBUG << "Initialized Tx Bridge";
tx_run.store(true);
tx_worker = std::thread(&Bridge::TxJob, this);
INFO << "Started Tx Worker";
DEBUG << "Started Tx Worker";
return 0;
}
@ -401,11 +403,11 @@ int Bridge::RxStart() {
if (err) {
return err;
}
INFO << "Init'd Rx Bridge";
DEBUG << "Init'd Rx Bridge";
rx_run.store(true);
rx_worker = std::thread(&Bridge::RxJob, this);
INFO << "Started Rx Worker";
DEBUG << "Started Rx Worker";
return 0;
}
@ -441,7 +443,7 @@ int Bridge::InitTxBridge() {
return 1;
}
INFO << "Created Tx Pipe at: " << tx_connection_string;
DEBUG << "Created Tx Pipe at: " << tx_connection_string;
return 0;
#else
@ -471,7 +473,7 @@ int Bridge::InitTxBridge() {
return 2;
}
INFO << "tx_sock created and bound on " << name.sun_path;
DEBUG << "tx_sock created and bound on " << name.sun_path;
return 0;
#endif
}
@ -509,7 +511,7 @@ int Bridge::InitRxBridge() {
return 1;
}
INFO << "Created Rx Pipe at: " << rx_connection_string;
DEBUG << "Created Rx Pipe at: " << rx_connection_string;
return 0;
#else
struct sockaddr_un name;
@ -538,7 +540,7 @@ int Bridge::InitRxBridge() {
return 2;
}
INFO << "rx_sock created and bound on " << name.sun_path;
DEBUG << "rx_sock created and bound on " << name.sun_path;
return 0;
#endif
}
@ -554,7 +556,7 @@ int Bridge::InitRxBridge() {
* int - 0 on success
******************************************************************************/
int Bridge::TxStop() {
INFO << "Stopping Tx";
DEBUG << "Stopping Tx";
tx_run.store(false);
@ -598,7 +600,7 @@ int Bridge::TxStop() {
}
#endif
INFO << "Tx stopped";
DEBUG << "Tx stopped";
return 0;
}
@ -613,7 +615,7 @@ int Bridge::TxStop() {
* int - 0 on success
******************************************************************************/
int Bridge::RxStop() {
INFO << "Stopping Rx";
DEBUG << "Stopping Rx";
rx_run.store(false);
@ -670,6 +672,6 @@ int Bridge::RxStop() {
#endif
INFO << "Rx stopped";
DEBUG << "Rx stopped";
return 0;
}

22
Software/waveview/scope_link/src/controller.cpp
View File

@ -37,7 +37,7 @@ controller::~controller()
delete postProcessorThread;
delete bridgeThread;
INFO << "Controller Destroyed";
DEBUG << "Controller Destroyed";
}
/*******************************************************************************
@ -58,15 +58,15 @@ void controller::controllerLoop()
while (stopController.load() == false) {
while (stopController.load() == false &&
controllerQueue_rx.pop(currentPacket)) {
INFO << "Controller processing a packet";
DEBUG << "Controller processing a packet";
// execute the packet command
switch (currentPacket->command) {
case 1:
INFO << "Packet command 1";
DEBUG << "Packet command 1";
break;
case 2:
INFO << "Packet command 2";
DEBUG << "Packet command 2";
break;
default:
ERROR << "Unknown packet command";
@ -92,7 +92,7 @@ void controller::controllerLoop()
******************************************************************************/
void controller::controllerPause()
{
INFO << "Pausing pipeline";
DEBUG << "Pausing pipeline";
processorThread->processorPause();
triggerThread->triggerPause();
postProcessorThread->postProcessorPause();
@ -111,7 +111,7 @@ void controller::controllerPause()
******************************************************************************/
void controller::controllerUnPause()
{
INFO << "Unpausing pipeline";
DEBUG << "Unpausing pipeline";
processorThread->processorUnpause();
triggerThread->triggerUnpause();
postProcessorThread->postProcessorUnpause();
@ -152,19 +152,19 @@ void controller::controllerFlush()
// Clear queues
size_t count = 0;
count = (*dataQueue).consume_all(bufferFunctor);
INFO << "Flushed inputQueue: " << count;
DEBUG << "Flushed inputQueue: " << count;
count = triggerProcessorQueue.consume_all(bufferFunctor);
INFO << "Flushed triggeredQueue: " << count;
DEBUG << "Flushed triggeredQueue: " << count;
// Clear persistence buffer
processorThread->flushPersistence();
INFO << "Flushed persistence buffer";
DEBUG << "Flushed persistence buffer";
// count = preProcessorQueue.consume_all(bufferFunctor);
// INFO << "Flushed preProcessorQueue: " << count;
// DEBUG << "Flushed preProcessorQueue: " << count;
count = processorPostProcessorQueue_1.consume_all(free);
INFO << "Flushed postProcessorQueue: " << count;
DEBUG << "Flushed postProcessorQueue: " << count;
}
/*******************************************************************************

22
Software/waveview/scope_link/src/logger.cpp
View File

@ -7,7 +7,7 @@
#include "logger.hpp"
namespace attrs = boost::log::attributes;
//namespace attrs = boost::log::attributes;
namespace expr = boost::log::expressions;
namespace logging = boost::log;
@ -45,3 +45,23 @@ BOOST_LOG_GLOBAL_LOGGER_INIT(my_logger, logger_t)
return lg;
}
/*******************************************************************************
* convert_int()
*
* converts an integer to a hex string.
*
* Arguments:
* int n - integer to convert.
*
* Return:
* string - integer n as an uppercase string.
******************************************************************************/
std::string convert_int(int n)
{
std::stringstream ss;
ss << std::uppercase << std::hex;
ss << n;
return ss.str();
}

3
Software/waveview/scope_link/src/main.cpp
View File

@ -184,8 +184,7 @@ void runCli() {
bool parseThings = true;
while(parseThings) {
INFO << "Input a command";
printf("> ");
INFO << "Input a command\n>";
std::string line;
std::getline(std::cin, line);

18
Software/waveview/scope_link/src/postProcessor.cpp
View File

@ -53,7 +53,7 @@ postProcessor::~postProcessor(void)
postProcessorStop();
postProcessorThread.join();
INFO << "Destroyed post processor";
DEBUG << "Destroyed post processor";
}
/*******************************************************************************
@ -80,7 +80,7 @@ void postProcessor::coreLoop()
while (pauseTransfer.load() == false &&
inputQueue->pop(currentWindow)) {
INFO << "post processing next window";
DEBUG << "post processing next window";
// TODO: Could do each channel in parrallel
for (uint8_t j = 0; j < numCh; j++) {
@ -89,12 +89,12 @@ void postProcessor::coreLoop()
// Post process window
// TODO: Add interpolation here.
std::cout << "Post Processed window";
std::string dbgMsg = "Post Processed window ";
for (uint32_t i = 0; i < windowSize; i++) {
postWindow[i] = currentWindow[i * numCh + j];
std::cout << " " << (int)currentWindow[i * numCh + j];
dbgMsg += std::to_string(currentWindow[i * numCh + j]) + " ";
}
std::cout << std::endl;
DEBUG << dbgMsg;
// Pass processed window to next stage
currentPacket = (EVPacket*)malloc(sizeof(EVPacket));
@ -143,7 +143,7 @@ void postProcessor::setCh (int8_t newCh)
void postProcessor::postProcessorStart()
{
stopTransfer.store(false);
INFO << "Starting post processing";
DEBUG << "Starting post processing";
}
/*******************************************************************************
@ -160,7 +160,7 @@ void postProcessor::postProcessorStart()
void postProcessor::postProcessorStop()
{
stopTransfer.store(true);
INFO << "Stopping post processing";
DEBUG << "Stopping post processing";
}
/*******************************************************************************
@ -177,7 +177,7 @@ void postProcessor::postProcessorStop()
void postProcessor::postProcessorUnpause()
{
pauseTransfer.store(false);
INFO << "unpausing post processing";
DEBUG << "unpausing post processing";
}
/*******************************************************************************
@ -194,5 +194,5 @@ void postProcessor::postProcessorUnpause()
void postProcessor::postProcessorPause()
{
pauseTransfer.store(true);
INFO << "pausing post processing";
DEBUG << "pausing post processing";
}

42
Software/waveview/scope_link/src/processor.cpp
View File

@ -2,8 +2,6 @@
#include "logger.hpp"
#include "common.hpp"
#define DBG
Processor::Processor(
boost::lockfree::queue<buffer*, boost::lockfree::fixed_sized<false>> *inputQ,
boost::lockfree::queue<int8_t*, boost::lockfree::fixed_sized<false>> *outputQ)
@ -34,36 +32,36 @@ Processor::Processor(
Processor::~Processor(void)
{
INFO << "Processor Destructor Called";
DEBUG << "Processor Destructor Called";
// Stop the transer and join thread
processorPause();
processorStop();
processorThread.join();
INFO << "Destroyed processor thread";
DEBUG << "Destroyed processor thread";
}
// Returns the offset of the next trigger in the current buffer
bool Processor::findNextTrigger(buffer *currentBuffer, uint32_t* p_bufCol)
{
INFO << "** Finding Next Trigger **";
INFO << "p_bufCol: " << *p_bufCol;
DEBUG << "** Finding Next Trigger **";
DEBUG << "p_bufCol: " << *p_bufCol;
uint32_t t_offset = 0;
// Find which 64 block the buffer is in
uint32_t t_64offset = (*p_bufCol / 64);
INFO << "p_bufCol: " << *p_bufCol
DEBUG << "p_bufCol: " << *p_bufCol
<< " t_offset: " << t_offset
<< " t_64offset: " << t_64offset;
if (windowCol != 0) {
// Partialy filled window
if (*p_bufCol == 0) {
INFO << "Partial Window. Fill the rest of the widow";
DEBUG << "Partial Window. Fill the rest of the widow";
return true;
} else {
INFO << "Partial Window. bufferCol = 0 and get new buffer";
DEBUG << "Partial Window. bufferCol = 0 and get new buffer";
*p_bufCol = 0;
return false;
}
@ -76,13 +74,13 @@ bool Processor::findNextTrigger(buffer *currentBuffer, uint32_t* p_bufCol)
// Found a trigger, find exact position
t_offset = (int)(log2(currentBuffer->trigger[t_64offset]));
#ifdef DBG
INFO << "found Trigger in 64: " << t_64offset
DEBUG << "found Trigger in 64: " << t_64offset
<< " with val: " << currentBuffer->trigger[t_64offset]
<< " t_offset: " << t_offset;
#endif
t_offset = (64 - 1) - t_offset;
#ifdef DBG
INFO << "t_64offset corrected: " << t_64offset;
DEBUG << "t_64offset corrected: " << t_64offset;
#endif
break;
}
@ -91,11 +89,11 @@ bool Processor::findNextTrigger(buffer *currentBuffer, uint32_t* p_bufCol)
if (t_64offset >= BUFFER_SIZE/64) {
// No trigger found in buffer
*p_bufCol = BUFFER_SIZE;
INFO << "End of buffer reached, go to next one";
DEBUG << "End of buffer reached, go to next one";
return false;
} else {
*p_bufCol = ((t_offset) + (t_64offset * 64));
INFO << "t_offset: " << t_offset
DEBUG << "t_offset: " << t_offset
<< " t_64_offset: " << t_64offset;
return true;
}
@ -120,7 +118,7 @@ void Processor::coreLoop()
windowStored.load() == false &&
inputQueue->pop(currentBuffer)) {
INFO << "*** New Buffer ***";
DEBUG << "*** New Buffer ***";
// New buffer, reset variables
count++;
bufferCol = 0;
@ -133,7 +131,7 @@ void Processor::coreLoop()
// - remaining space in a buffer
copyCount = std::min(windowSize - windowCol, BUFFER_SIZE/numCh - bufferCol);
INFO << "bufferCol: " << bufferCol
DEBUG << "bufferCol: " << bufferCol
<< " copyCount: " << copyCount;
// Copy samples into the window
@ -144,7 +142,7 @@ void Processor::coreLoop()
bufferCol += copyCount;
windowCol += copyCount;
INFO << "bufferCol: " << bufferCol
DEBUG << "bufferCol: " << bufferCol
<< " windowCol: " << windowCol
<< " windowSize: " << windowSize
<< std::endl;
@ -162,11 +160,11 @@ void Processor::coreLoop()
// Push it into the next 64 space so we don't
// trigger on the same spot twice
bufferCol += 64;
INFO << "full window. windowCol: "
DEBUG << "full window. windowCol: "
<< windowCol;
} else {
// Partial window coppied
INFO << "partial window. windowCol: "
DEBUG << "partial window. windowCol: "
<< windowCol;
}
@ -251,26 +249,26 @@ std::chrono::high_resolution_clock::time_point Processor::getTimeWritten()
void Processor::processorStart()
{
stopTransfer.store(false);
INFO << "Starting processing";
DEBUG << "Starting processing";
}
void Processor::processorStop()
{
stopTransfer.store(true);
INFO << "Stopping processing";
DEBUG << "Stopping processing";
}
// Control the inner loop
void Processor::processorUnpause()
{
pauseTransfer.store(false);
INFO << "unpausing processing";
DEBUG << "unpausing processing";
}
void Processor::processorPause()
{
pauseTransfer.store(true);
INFO << "pausing processing";
DEBUG << "pausing processing";
}
// Statistics

35
Software/waveview/scope_link/src/trigger.cpp
View File

@ -1,5 +1,4 @@
#include "trigger.hpp"
#define DBG
Trigger::Trigger(boost::lockfree::queue<buffer*, boost::lockfree::fixed_sized<false>> *inputQ,
boost::lockfree::queue<buffer*, boost::lockfree::fixed_sized<false>> *outputQ,
@ -36,14 +35,14 @@ Trigger::Trigger(boost::lockfree::queue<buffer*, boost::lockfree::fixed_sized<fa
Trigger::~Trigger(void)
{
INFO << "Trigger Destructor Called";
DEBUG << "Trigger Destructor Called";
// Stop the transer and join thread
stopTrigger.store(true);
pauseTrigger.store(true);
triggerThread.join();
INFO << "Destroyed Trigger Thread";
DEBUG << "Destroyed Trigger Thread";
}
#ifdef DBG
@ -52,9 +51,7 @@ uint32_t temp = 0;
void Trigger::checkTriggerFalling(buffer* currentBuffer)
{
#ifdef DBG
INFO << "Checking a Trigger with #ch: " << (int)numCh << " triggering on ch: " << (int)triggerCh;
#endif
DEBUG << "Checking a Trigger with #ch: " << (int)numCh << " triggering on ch: " << (int)triggerCh;
// Compute the trigger
for (int i = 0; i < (BUFFER_SIZE/64)/numCh; i++) {
currentBuffer->trigger[i] =
@ -189,7 +186,7 @@ void Trigger::checkTriggerFalling(buffer* currentBuffer)
#ifdef DBG
if (temp < 32) {
INFO << "Trigger index: " << i << " value: " << std::hex << currentBuffer->trigger[i];
DEBUG << "Trigger index: " << i << " value: " << std::hex << currentBuffer->trigger[i];
temp++;
}
#endif
@ -198,9 +195,7 @@ void Trigger::checkTriggerFalling(buffer* currentBuffer)
void Trigger::checkTriggerRising(buffer* currentBuffer)
{
#ifdef DBG
INFO << "Checking a Trigger with #ch: " << (int)numCh << " triggering on ch: " << (int)triggerCh;
#endif
DEBUG << "Checking a Trigger with #ch: " << (int)numCh << " triggering on ch: " << (int)triggerCh;
// Compute the trigger
for (int i = 0; i < (BUFFER_SIZE/64)/numCh; i++) {
currentBuffer->trigger[i] =
@ -335,7 +330,7 @@ void Trigger::checkTriggerRising(buffer* currentBuffer)
#ifdef DBG
if (temp < 32) {
INFO << "Trigger index: " << i << " value: " << std::hex << currentBuffer->trigger[i];
DEBUG << "Trigger index: " << i << " value: " << std::hex << currentBuffer->trigger[i];
temp++;
}
#endif
@ -352,10 +347,10 @@ void Trigger::coreLoop()
ERROR << "Input Queue null in trigger core loop";
} else {
while (inputQueue->pop(currentBuffer) == false && stopTrigger.load() == false) {
// INFO << "Waiting for first data element";
// DEBUG << "Waiting for first data element";
std::this_thread::sleep_for(std::chrono::microseconds(100));
};
INFO << "Core Loop Entered";
DEBUG << "Core Loop Entered";
// Outer loop
while (stopTrigger.load() == false) {
@ -367,7 +362,7 @@ void Trigger::coreLoop()
if (inputQueue->pop(nextBuffer)) {
count++;
INFO << "trigger next buffer";
DEBUG << "trigger next buffer";
// copy first value from next buffer to current buffer
currentBuffer->data[BUFFER_SIZE] = nextBuffer->data[0];
@ -422,14 +417,14 @@ void Trigger::setRising()
{
triggerPause();
risingEdge = true;
INFO << "Triggering on rising edge";
DEBUG << "Triggering on rising edge";
}
void Trigger::setFalling()
{
triggerPause();
risingEdge = false;
INFO << "Triggering on falling edge";
DEBUG << "Triggering on falling edge";
}
bool Trigger::getTriggerStatus()
@ -440,25 +435,25 @@ bool Trigger::getTriggerStatus()
void Trigger::triggerStop()
{
stopTrigger.store(true);
INFO << "Stopping Trigger";
DEBUG << "Stopping Trigger";
}
void Trigger::triggerStart()
{
stopTrigger.store(false);
INFO << "Starting Trigger";
DEBUG << "Starting Trigger";
}
void Trigger::triggerPause()
{
pauseTrigger.store(true);
INFO << "Pausing Trigger";
DEBUG << "Pausing Trigger";
}
void Trigger::triggerUnpause()
{
pauseTrigger.store(false);
INFO << "Unpausing Trigger";
DEBUG << "Unpausing Trigger";
}
uint32_t Trigger::getCount()