Skip to content

Commit edc37c8

Browse files
committed
Refactor message logging.
1 parent ce228f1 commit edc37c8

26 files changed

+1789
-332
lines changed

SerialPrograms/Source/Controllers/SerialPABotBase/Connection/BotBaseMessage.h

Lines changed: 62 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -10,8 +10,11 @@
1010
#include <stdint.h>
1111
#include <cstring>
1212
#include <string>
13+
#include "Common/Cpp/PrettyPrint.h"
1314
#include "Common/Cpp/Exceptions.h"
1415
#include "Common/Cpp/LifetimeSanitizer.h"
16+
#include "Common/SerialPABotBase/SerialPABotBase_Protocol.h"
17+
#include "CommonFramework/GlobalSettingsPanel.h"
1518

1619
namespace PokemonAutomation{
1720

@@ -73,6 +76,65 @@ class BotBaseRequest{
7376

7477

7578

79+
class BotBaseMessageType{
80+
public:
81+
template <typename ChildType>
82+
static const BotBaseMessageType& instance(){
83+
static const ChildType type;
84+
return type;
85+
}
86+
87+
BotBaseMessageType(const char* name, uint8_t type, uint8_t body_size)
88+
: m_name(name)
89+
, m_type(type)
90+
, m_size(body_size)
91+
{}
92+
93+
uint8_t type() const{
94+
return m_type;
95+
}
96+
97+
friend bool operator<(const BotBaseMessageType& x, const BotBaseMessageType& y){
98+
return x.m_type < y.m_type;
99+
}
100+
101+
102+
public:
103+
virtual bool should_print(const std::string& body) const{
104+
if (GlobalSettings::instance().LOG_EVERYTHING){
105+
return true;
106+
}
107+
if (PABB_MSG_IS_ACK(m_type)){
108+
return false;
109+
}
110+
return true;
111+
}
112+
virtual bool is_valid(const std::string& body) const{
113+
return body.size() == m_size;
114+
}
115+
virtual std::string tostr(const std::string& body) const{
116+
std::string ret;
117+
ret += "(0x" + tostr_hex(m_type) + ") ";
118+
ret += m_name;
119+
if (!is_valid(body)){
120+
ret += ": (Invalid: Size = " + std::to_string(body.size()) + ")";
121+
}
122+
return ret;
123+
}
124+
125+
126+
private:
127+
const char* m_name;
128+
const uint8_t m_type;
129+
const uint8_t m_size; // Excluding header and CRC.
130+
};
131+
132+
133+
134+
135+
136+
137+
76138

77139
}
78140
#endif

SerialPrograms/Source/Controllers/SerialPABotBase/Connection/MessageLogger.cpp

Lines changed: 1 addition & 75 deletions
Original file line numberDiff line numberDiff line change
@@ -5,88 +5,14 @@
55
*/
66

77
#include "Common/Cpp/PrettyPrint.h"
8-
#include "Common/SerialPABotBase/SerialPABotBase_Protocol.h"
9-
#include "Controllers/SerialPABotBase/Connection/MessageConverter.h"
10-
#include "BotBaseMessage.h"
118
#include "MessageLogger.h"
129

1310
namespace PokemonAutomation{
1411

1512

16-
//void MessageLogger::log(std::string msg){
17-
// log(msg);
18-
//}
19-
void MessageLogger::on_send(const BotBaseMessage& message, bool is_retransmit){
20-
bool print = false;
21-
do{
22-
if (is_retransmit){
23-
print = true;
24-
}
25-
if (PABB_MSG_IS_REQUEST(message.type)){
26-
print = true;
27-
}
28-
if (PABB_MSG_IS_COMMAND(message.type)){
29-
print = true;
30-
}
31-
if (message.type == PABB_MSG_REQUEST_CLOCK){
32-
print = false;
33-
}
34-
#if 0
35-
if (message.type == PABB_MSG_CONTROLLER_STATE){
36-
// pabb_controller_state body;
37-
// memcpy(&body, message.body.c_str(), sizeof(pabb_controller_state));
38-
// print = body.ticks >= 5;
39-
print = false;
40-
}
41-
#endif
42-
43-
if (m_log_everything.load(std::memory_order_relaxed)){
44-
print = true;
45-
}
46-
47-
}while (false);
48-
if (!print){
49-
return;
50-
}
51-
std::string str = message_to_string(message);
52-
if (str.empty()){
53-
return;
54-
}
55-
if (is_retransmit){
56-
log("Re-Send: " + str, COLOR_DARKGREEN);
57-
}else{
58-
log("Sending: " + str, COLOR_DARKGREEN);
59-
}
60-
}
61-
void MessageLogger::on_recv(const BotBaseMessage& message){
62-
bool print = false;
63-
do{
64-
if (PABB_MSG_IS_ERROR(message.type)){
65-
print = true;
66-
}
67-
if (PABB_MSG_IS_INFO(message.type)){
68-
print = true;
69-
}
70-
71-
if (m_log_everything.load(std::memory_order_relaxed)){
72-
print = true;
73-
}
74-
75-
}while (false);
76-
if (!print){
77-
return;
78-
}
79-
std::string str = message_to_string(message);
80-
if (!str.empty()){
81-
log("Receive: " + str, COLOR_DARKGREEN);
82-
}
83-
}
84-
85-
8613

8714
SerialLogger::SerialLogger(Logger& logger, bool log_everything)
88-
: MessageLogger(log_everything)
89-
, m_logger(logger)
15+
: m_logger(logger)
9016
, m_history(200)
9117
{}
9218
void SerialLogger::log(const char* msg, Color color){

SerialPrograms/Source/Controllers/SerialPABotBase/Connection/MessageLogger.h

Lines changed: 1 addition & 24 deletions
Original file line numberDiff line numberDiff line change
@@ -7,39 +7,16 @@
77
#ifndef PokemonAutomation_MessageLogger_H
88
#define PokemonAutomation_MessageLogger_H
99

10-
#include <atomic>
1110
#include "Common/Cpp/AbstractLogger.h"
1211
#include "Common/Cpp/Time.h"
1312
#include "Common/Cpp/Containers/CircularBuffer.h"
1413
#include "Common/Cpp/Concurrency/SpinLock.h"
15-
#include "MessageSniffer.h"
1614

1715
namespace PokemonAutomation{
1816

1917

20-
class MessageLogger : public Logger, public MessageSniffer{
21-
public:
22-
MessageLogger(bool log_everything = false)
23-
: m_log_everything_owner(log_everything)
24-
, m_log_everything(m_log_everything_owner)
25-
{}
26-
MessageLogger(std::atomic<bool>& log_everything)
27-
: m_log_everything_owner(false)
28-
, m_log_everything(log_everything)
29-
{}
30-
31-
32-
virtual void on_send(const BotBaseMessage& message, bool is_retransmit) override;
33-
virtual void on_recv(const BotBaseMessage& message) override;
34-
35-
private:
36-
std::atomic<bool> m_log_everything_owner;
37-
std::atomic<bool>& m_log_everything;
38-
};
39-
40-
4118

42-
class SerialLogger : public MessageLogger{
19+
class SerialLogger : public Logger{
4320
public:
4421
SerialLogger(Logger& logger, bool log_everything);
4522

SerialPrograms/Source/Controllers/SerialPABotBase/Connection/PABotBase.cpp

Lines changed: 2 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -9,7 +9,8 @@
99
#include "Common/Cpp/PanicDump.h"
1010
#include "Common/Cpp/Concurrency/SpinPause.h"
1111
#include "Common/SerialPABotBase/SerialPABotBase_Protocol.h"
12-
#include "Controllers/SerialPABotBase/SerialPABotBase_Routines_Protocol.h"
12+
#include "Controllers/SerialPABotBase/Messages/SerialPABotBase_MessageWrappers_BaseProtocol_StaticRequests.h"
13+
#include "Controllers/SerialPABotBase/Messages/SerialPABotBase_MessageWrappers_BaseProtocol_CommandQueue.h"
1314
#include "PABotBase.h"
1415

1516
//#include <iostream>
@@ -40,7 +41,6 @@ namespace PokemonAutomation{
4041
PABotBase::PABotBase(
4142
Logger& logger,
4243
std::unique_ptr<StreamConnection> connection,
43-
MessageLogger* message_logger,
4444
std::chrono::milliseconds retransmit_delay
4545
)
4646
: PABotBaseConnection(logger, std::move(connection))
@@ -52,8 +52,6 @@ PABotBase::PABotBase(
5252
, m_state(State::RUNNING)
5353
, m_error(false)
5454
{
55-
set_sniffer(message_logger);
56-
5755
// We must initialize this last because it will trigger the lifetime
5856
// sanitizer if it beats it to construction.
5957
m_retransmit_thread = Thread([this]{

SerialPrograms/Source/Controllers/SerialPABotBase/Connection/PABotBase.h

Lines changed: 1 addition & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -41,20 +41,17 @@
4141
namespace PokemonAutomation{
4242

4343

44-
class PABotBase : public BotBaseController, private PABotBaseConnection{
44+
class PABotBase : public BotBaseController, public PABotBaseConnection{
4545
static const seqnum_t MAX_SEQNUM_GAP = (seqnum_t)-1 >> 2;
4646

4747
public:
4848
PABotBase(
4949
Logger& logger,
5050
std::unique_ptr<StreamConnection> connection,
51-
MessageLogger* message_logger = nullptr,
5251
std::chrono::milliseconds retransmit_delay = std::chrono::milliseconds(100)
5352
);
5453
virtual ~PABotBase();
5554

56-
using PABotBaseConnection::set_sniffer;
57-
5855
void connect();
5956
virtual void stop(std::string error_message = "") override;
6057

SerialPrograms/Source/Controllers/SerialPABotBase/Connection/PABotBaseConnection.cpp

Lines changed: 39 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@
44
*
55
*/
66

7+
#include "Common/Cpp/Exceptions.h"
78
#include "Common/CRC32.h"
89
#include "Common/SerialPABotBase/SerialPABotBase_Protocol.h"
910
//#include "Controllers/SerialPABotBase/Connection/MessageConverter.h"
@@ -16,12 +17,11 @@
1617

1718
namespace PokemonAutomation{
1819

19-
MessageSniffer null_sniffer;
20+
2021

2122
PABotBaseConnection::PABotBaseConnection(Logger& logger, std::unique_ptr<StreamConnection> connection)
2223
: m_connection(std::move(connection))
2324
, m_logger(logger)
24-
, m_sniffer(&null_sniffer)
2525
{
2626
m_connection->add_listener(*this);
2727
}
@@ -38,11 +38,16 @@ void PABotBaseConnection::safely_stop(){
3838
}
3939

4040

41-
void PABotBaseConnection::set_sniffer(MessageSniffer* sniffer){
42-
if (sniffer == nullptr){
43-
sniffer = &null_sniffer;
41+
void PABotBaseConnection::add_message_printer(const BotBaseMessageType& type){
42+
auto ret = m_printers.emplace(type.type(), &type);
43+
if (ret.second){
44+
return;
4445
}
45-
m_sniffer = sniffer;
46+
throw InternalProgramError(
47+
nullptr,
48+
PA_CURRENT_FUNCTION,
49+
"Duplicate Message Type: 0x" + tostr_hex(type.type())
50+
);
4651
}
4752

4853

@@ -63,7 +68,18 @@ void PABotBaseConnection::send_message(const BotBaseMessage& message, bool is_re
6368
}
6469

6570
// log("Sending: " + message_to_string(type, msg));
66-
m_sniffer->on_send(message, is_retransmit);
71+
{
72+
std::string str = is_retransmit ? "Re-send" : "Sending";
73+
auto iter = m_printers.find(message.type);
74+
if (iter == m_printers.end()){
75+
m_logger.log(str + ": Unknown Message Type (0x" + tostr_hex(message.type) + ")", COLOR_RED);
76+
}else if (is_retransmit || iter->second->should_print(message.body)){
77+
m_logger.log(
78+
str + ": " + iter->second->tostr(message.body),
79+
is_retransmit ? COLOR_ORANGE : COLOR_DARKGREEN
80+
);
81+
}
82+
}
6783

6884
size_t total_bytes = PABB_PROTOCOL_OVERHEAD + message.body.size();
6985
if (total_bytes > PABB_PROTOCOL_MAX_PACKET_SIZE){
@@ -91,16 +107,16 @@ void PABotBaseConnection::push_error_byte(ErrorBatchType type, char byte){
91107
case ErrorBatchType::NO_ERROR_:
92108
break;
93109
case ErrorBatchType::ZERO_BYTES:
94-
m_logger.log("Skipped " + std::to_string(m_current_error_batch.size()) + " zero byte(s).");
110+
m_logger.log("Skipped " + std::to_string(m_current_error_batch.size()) + " zero byte(s).", COLOR_RED);
95111
break;
96112
case ErrorBatchType::FF_BYTES:
97-
m_logger.log("Skipped " + std::to_string(m_current_error_batch.size()) + " 0xff byte(s).");
113+
m_logger.log("Skipped " + std::to_string(m_current_error_batch.size()) + " 0xff byte(s).", COLOR_RED);
98114
break;
99115
case ErrorBatchType::ASCII_BYTES:
100-
m_logger.log("Received possible ASCII: " + m_current_error_batch);
116+
m_logger.log("Received possible ASCII: " + m_current_error_batch, COLOR_RED);
101117
break;
102118
case ErrorBatchType::OTHER:
103-
// m_logger.log("Skipped " + std::to_string(m_current_error_batch.size()) + " invalid length byte(s).");
119+
// m_logger.log("Skipped " + std::to_string(m_current_error_batch.size()) + " invalid length byte(s).", COLOR_RED);
104120
break;
105121
}
106122

@@ -118,7 +134,7 @@ void PABotBaseConnection::on_recv(const void* data, size_t bytes){
118134
uint8_t length = ~m_recv_buffer[0];
119135

120136
if (m_recv_buffer[0] == 0){
121-
// m_logger.log("Skipping zero byte.");
137+
// m_logger.log("Skipping zero byte.", COLOR_RED);
122138
push_error_byte(ErrorBatchType::ZERO_BYTES, 0);
123139
m_recv_buffer.pop_front();
124140
continue;
@@ -129,7 +145,7 @@ void PABotBaseConnection::on_recv(const void* data, size_t bytes){
129145
if (length == 0){
130146
push_error_byte(ErrorBatchType::FF_BYTES, ~length);
131147
}else{
132-
m_logger.log("Message is too short: bytes = " + std::to_string(length));
148+
m_logger.log("Message is too short: bytes = " + std::to_string(length), COLOR_RED);
133149
push_error_byte(ErrorBatchType::OTHER, ~length);
134150
}
135151
m_recv_buffer.pop_front();
@@ -142,7 +158,7 @@ void PABotBaseConnection::on_recv(const void* data, size_t bytes){
142158
// std::string text = ascii < 32
143159
// ? ", ascii = " + std::to_string(ascii)
144160
// : std::string(", char = ") + ascii;
145-
// m_logger.log("Message is too long: bytes = " + std::to_string(length) + text);
161+
// m_logger.log("Message is too long: bytes = " + std::to_string(length) + text, COLOR_RED);
146162
push_error_byte(ErrorBatchType::ASCII_BYTES, ~length);
147163
m_recv_buffer.pop_front();
148164
continue;
@@ -169,7 +185,7 @@ void PABotBaseConnection::on_recv(const void* data, size_t bytes){
169185
// Compare
170186
// std::cout << checksumA << " / " << checksumE << std::endl;
171187
if (checksumA != checksumE){
172-
m_logger.log("Invalid Checksum: bytes = " + std::to_string(length));
188+
m_logger.log("Invalid Checksum: bytes = " + std::to_string(length), COLOR_RED);
173189
// std::cout << checksumA << " / " << checksumE << std::endl;
174190
// log(message_to_string(message[1], &message[2], length - PABB_PROTOCOL_OVERHEAD));
175191
m_recv_buffer.pop_front();
@@ -179,7 +195,14 @@ void PABotBaseConnection::on_recv(const void* data, size_t bytes){
179195
m_recv_buffer.erase(m_recv_buffer.begin(), m_recv_buffer.begin() + length);
180196

181197
BotBaseMessage msg(message[1], std::string(&message[2], length - PABB_PROTOCOL_OVERHEAD));
182-
m_sniffer->on_recv(msg);
198+
{
199+
auto iter = m_printers.find(msg.type);
200+
if (iter == m_printers.end()){
201+
m_logger.log("Receive: Unknown Message Type (0x" + tostr_hex(msg.type) + ")", COLOR_RED);
202+
}else if (iter->second->should_print(msg.body)){
203+
m_logger.log("Receive: " + iter->second->tostr(msg.body), COLOR_DARKGREEN);
204+
}
205+
}
183206
on_recv_message(std::move(msg));
184207
}
185208
}

0 commit comments

Comments
 (0)