Skip to content

Commit 323a448

Browse files
authored
Unify logging (#60)
1 parent 9fc265a commit 323a448

File tree

10 files changed

+80
-72
lines changed

10 files changed

+80
-72
lines changed

src/BridgePerVxlanRenderer.cpp

Lines changed: 8 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -11,24 +11,24 @@ BridgePerVxlanRenderer::BridgePerVxlanRenderer()
1111

1212
void BridgePerVxlanRenderer::setup_station(const Station& station) {
1313
std::lock_guard g(renderer_mutex);
14-
WMLOG(DEBUG) << "Calling: setup_station(" << station << ")";
14+
WMLOG(DEBUG) << "Calling setup_station station=" << station;
1515

1616
uint32_t vni = station.vni();
1717
socket.create_vxlan_iface(vni);
1818
socket.create_bridge_for_vni(vni);
19-
socket.add_iface_bridge("bridge" + std::to_string(vni), "vxlan" + std::to_string(vni));
2019

2120
if (not station.vlan_id.has_value()) {
22-
throw std::runtime_error("The station " + station.mac.string() + " has no vlan_id");
21+
throw std::runtime_error("Station has no vlan_id station=" + station.mac.string());
2322
}
2423

2524
socket.add_iface_bridge("bridge" + std::to_string(station.vni()), station.vlan_interface_name());
25+
WMLOG(DEBUG) << "Finished bridge setup.";
2626
}
2727

2828
void BridgePerVxlanRenderer::cleanup(const std::function<std::vector<Station>()>& get_stations) {
2929
std::lock_guard g(renderer_mutex);
3030
std::unordered_set<uint32_t> connected_station_vnis(0);
31-
WMLOG(DEBUG) << "Starting cleanup.";
31+
WMLOG(DEBUG) << "Started cleanup";
3232
int sta_counter = 0;
3333
for (auto& station : get_stations()) {
3434
connected_station_vnis.emplace(station.vni());
@@ -41,17 +41,17 @@ void BridgePerVxlanRenderer::cleanup(const std::function<std::vector<Station>()>
4141
existing_interfaces.erase(vni);
4242
}
4343
for (const auto vni : existing_interfaces) {
44-
WMLOG(DEBUG) << "Deleting VNI " << vni;
44+
WMLOG(DEBUG) << "Deleting vni=" << vni;
4545
try {
4646
socket.delete_interface("vxlan" + std::to_string(vni));
4747
} catch (const std::exception&) {
48-
WMLOG(ERROR) << "Could not delete vxlan interface vni: " << vni;
48+
WMLOG(ERROR) << "Could not delete vxlan vni=" << vni;
4949
}
5050
try {
5151
socket.delete_interface("bridge" + std::to_string(vni));
5252
} catch (const std::exception&) {
53-
WMLOG(ERROR) << "Could not delete bridge vni: " << vni;
53+
WMLOG(ERROR) << "Could not delete bridge vni=" << vni;
5454
}
5555
}
56-
WMLOG(DEBUG) << "Cleanup finished, " << sta_counter << " stations connected.";
56+
WMLOG(DEBUG) << "Cleanup finished. Connected stations: " << sta_counter;
5757
}

src/ConfigParser.cpp

Lines changed: 5 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -28,7 +28,7 @@ ConfigParser ConfigParser::from_file(const std::string &config_path) {
2828
std::string line;
2929
std::ifstream config_file(config_path);
3030
if (!config_file.is_open()) {
31-
WMLOG(ERROR) << "Unable to read config file " << config_path << ". Using default config";
31+
WMLOG(ERROR) << "Using default configuartion because unable to read file config_path=" << config_path;
3232
return {};
3333
}
3434
return ConfigParser(config_file);
@@ -44,7 +44,7 @@ ConfigParser::ConfigParser(std::istream &istream) {
4444
}
4545
auto split = line.find(delimiter);
4646
if (split == std::string::npos) {
47-
throw std::runtime_error("Configuration line is invalid: " + line);
47+
throw std::runtime_error("Invalid configuration line=" + line);
4848
}
4949
std::string token = line.substr(0, split);
5050
trim(token);
@@ -60,7 +60,7 @@ ConfigParser::ConfigParser(std::istream &istream) {
6060
std::string ConfigParser::get_config_string(const std::string &option) const {
6161
auto got = config_options.find(option);
6262
if (got == config_options.end()) {
63-
throw std::out_of_range(std::string("Could not get option: ") + option);
63+
throw std::out_of_range(std::string("Could not get option=") + option);
6464
}
6565
return got->second;
6666
}
@@ -69,7 +69,8 @@ uint32_t ConfigParser::get_config_uint32(const std::string &option) const {
6969
std::string value = this->get_config_string(option);
7070
uint64_t result = std::stoull(value);
7171
if (result > std::numeric_limits<uint32_t>::max()) {
72-
throw std::range_error("Number is too large for uint32_t. Config option " + option + " with value " + value);
72+
throw std::range_error("Number is too large for uint32_t, therefore could not configure option=" + option +
73+
" value=" + value);
7374
}
7475
return result;
7576
}

src/Configuration.cpp

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -47,9 +47,9 @@ void Configuration::set_all_available_sockets_if_empty() {
4747
}
4848
}
4949
if (socknames.empty()) {
50-
throw std::runtime_error("No sockets were configured and no sockets could be found.");
50+
throw std::runtime_error("Could not configure sockets.");
5151
}
52-
WMLOG(DEBUG) << "No sockets were configured. Using all " << socknames.size() << " sockets available.";
52+
WMLOG(DEBUG) << "There were no sockets specified. Using all available sockets: " << socknames.size();
5353
}
5454
}
5555

@@ -67,7 +67,7 @@ void Configuration::apply_environment() { set_all_available_sockets_if_empty();
6767

6868
void Configuration::check_validity() const {
6969
if (min_vni > max_vni) {
70-
throw std::runtime_error("min_vni must be less than or equal to max_vni " + std::to_string(min_vni) + " > " +
71-
std::to_string(max_vni));
70+
throw std::runtime_error("min_vni <= max_vni but min_vni=" + std::to_string(min_vni) +
71+
" max_vni=" + std::to_string(max_vni));
7272
}
7373
}

src/EventLoop.cpp

Lines changed: 8 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -28,20 +28,21 @@ void EventLoop::loop_ipc_queue(const std::future<void>& future) {
2828

2929
void EventLoop::handle_connect(ipc::ConnectEvent* event) {
3030
event->station.vlan_id = caller.vlan_for_station(event->station);
31-
WMLOG(DEBUG) << "handle_connect called " << event->station << " with vlan_id "
32-
<< event->station.vlan_id.value_or(0);
33-
WMLOG(INFO) << "Station " << event->station << " connected to AP for VXLAN " << event->station.vni()
34-
<< " at interface " << event->station.sockname;
31+
WMLOG(DEBUG) << "Entering handle_connect station=" << event->station
32+
<< " vlan_id=" << event->station.vlan_id.value_or(0);
33+
WMLOG(INFO) << "Connected iface=" << event->station.sockname << " station=" << event->station.mac.string()
34+
<< " vni=" << event->station.vni();
3535
try {
3636
renderer.setup_station(event->station);
3737
processing_time_histogram.Observe(static_cast<double>(event->finished_processing()));
3838
} catch (std::runtime_error& err) {
39-
WMLOG(ERROR) << "station could not be bridged to vxlan interface: " << err.what()
40-
<< " - Will now send deauth packet";
39+
WMLOG(ERROR) << "Could not connect - Will now send DEAUTH packet. error=" << err.what()
40+
<< " iface=" << event->station.sockname << " station=" << event->station.mac.string()
41+
<< " vni=" << event->station.vni();
4142
caller.deauth_station(event->station);
4243
}
4344
}
4445

4546
void EventLoop::handle_disconnect(ipc::DisconnectEvent* event) {
46-
WMLOG(INFO) << "Station " << event->station << " disconnected from AP";
47+
WMLOG(INFO) << "Disconnected station=" << event->station.mac.string();
4748
}

src/MacAddress.cpp

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,7 @@ const int BITS_PER_BYTE = 8;
88

99
MacAddress::MacAddress(std::string serialized) : data(), serialized(serialized) {
1010
if (!std::regex_match(serialized, MAC_REGEX)) {
11-
throw std::runtime_error("MAC address not valid");
11+
throw std::runtime_error("Invalid station=" + serialized);
1212
}
1313
serialized.erase(std::remove(serialized.begin(), serialized.end(), ':'), serialized.end());
1414
for (size_t i = 0; i < MAC_NUM_BYTES; i++) {

src/ipc/Caller.cpp

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -20,7 +20,7 @@ uint32_t ipc::Caller::vlan_for_station(const Station &station) {
2020
return std::stol(line.substr(VLAN_ID_PREFIX.size(), line.size()));
2121
}
2222
}
23-
throw std::runtime_error("no vlan_id attribute found for station");
23+
throw std::runtime_error("Could not find vlan_id station=" + station.mac.string());
2424
}
2525

2626
std::vector<Station> ipc::Caller::connected_stations() {

src/ipc/Socket.cpp

Lines changed: 14 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -56,12 +56,12 @@ ipc::Socket::Socket(const std::chrono::duration<int>& timeout, const std::string
5656
std::string dest_path = Configuration::get_instance().hapd_sockdir + "/" + sockname;
5757
std::string local_path = "/var/run/wimoved." + random_name();
5858
if (unlink(local_path.c_str()) == 0) {
59-
WMLOG(DEBUG) << "Successfully unlinked socket" << local_path;
59+
WMLOG(DEBUG) << "Successfully unlinked socket local_path=" << local_path;
6060
}
6161

6262
sock_fd = socket(AF_UNIX, SOCK_DGRAM, 0);
6363
if (sock_fd == -1) {
64-
throw std::runtime_error(std::string("could not create socket: ") + std::strerror(errno));
64+
throw std::runtime_error(std::string("Could not create socket error=") + std::strerror(errno));
6565
}
6666
auto timeout_usec = std::chrono::duration_cast<std::chrono::microseconds>(timeout);
6767
struct timeval tv {};
@@ -74,29 +74,31 @@ ipc::Socket::Socket(const std::chrono::duration<int>& timeout, const std::string
7474
local.sun_path[sizeof(local.sun_path) - 1] = '\0';
7575
if (bind(sock_fd, reinterpret_cast<struct sockaddr*>(&local), sizeof(local)) == -1) {
7676
close(sock_fd);
77-
throw std::runtime_error("could not bind to socket " + dest_path + ": " + std::strerror(errno));
77+
throw std::runtime_error(std::string("Could not bind to socket error=") + std::strerror(errno) +
78+
std::string(" dest_path=") + dest_path);
7879
}
7980

8081
std::array<char, GETGRNAM_BUFFER_SIZE> buf{};
8182
struct group grp {};
8283
struct group* grp_result = nullptr;
8384
getgrnam_r(Configuration::get_instance().hapd_group.c_str(), &grp, buf.data(), buf.size(), &grp_result);
8485
if (grp_result == nullptr) {
85-
throw std::runtime_error(std::string("getgrnam failed: ") + std::strerror(errno));
86+
throw std::runtime_error(std::string("Failed getgrnam_r() error=") + std::strerror(errno));
8687
}
8788
if (chown(local_path.c_str(), -1, grp_result->gr_gid) == -1) {
88-
throw std::runtime_error(std::string("could not set socket group: ") + std::strerror(errno));
89+
throw std::runtime_error(std::string("Could not set socket group error=") + std::strerror(errno));
8990
}
9091
if (chmod(local_path.c_str(), LOCAL_SOCKET_PERMISSIONS) == -1) {
91-
throw std::runtime_error(std::string("could not set socket permissions: ") + std::strerror(errno));
92+
throw std::runtime_error(std::string("Could not set socket permissions error=") + std::strerror(errno));
9293
}
9394

9495
dest.sun_family = AF_UNIX;
9596
strncpy(dest.sun_path, dest_path.c_str(), sizeof(dest.sun_path));
9697
dest.sun_path[sizeof(dest.sun_path) - 1] = '\0';
9798
if (connect(sock_fd, reinterpret_cast<struct sockaddr*>(&dest), sizeof(dest)) == -1) {
9899
close(sock_fd);
99-
throw std::runtime_error("could not connect to socket at " + dest_path + " : " + std::strerror(errno));
100+
throw std::runtime_error(std::string("Could not connect to socket error=") + std::strerror(errno) +
101+
std::string(" dest_path=") + dest_path);
100102
}
101103
}
102104

@@ -105,10 +107,10 @@ ipc::Socket::~Socket() {
105107
return;
106108
}
107109
if (close(sock_fd) == -1) {
108-
WMLOG(ERROR) << "Could not close socket: " << std::strerror(errno) << "\n";
110+
WMLOG(ERROR) << "Could not close socket error=" << std::strerror(errno) << "\n";
109111
}
110112
if (unlink(local.sun_path) != 0) {
111-
WMLOG(ERROR) << "Could not unlink socket: " << std::strerror(errno) << "\n";
113+
WMLOG(ERROR) << "Could not unlink socket error=" << std::strerror(errno) << "\n";
112114
}
113115
}
114116

@@ -118,7 +120,7 @@ void ipc::Socket::send_command(const std::vector<std::string>& args) {
118120

119121
ssize_t err = send(sock_fd, command.c_str(), command.size(), 0);
120122
if (err < 0) {
121-
throw std::runtime_error(std::string("could not send_command to socket: ") + std::strerror(errno));
123+
throw std::runtime_error(std::string("Could not send to socket error=") + std::strerror(errno));
122124
}
123125
}
124126

@@ -136,10 +138,10 @@ std::string ipc::Socket::receive() {
136138
return buf.substr(0, len);
137139
}
138140
if (errno == EAGAIN) {
139-
throw TimeoutException("timeout in recv() from hostapd");
141+
throw TimeoutException("Timeout from hostapd recv()");
140142
}
141143
if (errno != EINTR) {
142-
throw std::runtime_error(std::string("could not recv from socket: ") + std::strerror(errno));
144+
throw std::runtime_error(std::string("Could not receive from socket error=") + std::strerror(errno));
143145
}
144146
}
145147
}

src/ipc/Subscriber.cpp

Lines changed: 11 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -16,14 +16,14 @@ const std::string HOSTAPD_GLOBAL = "global";
1616
static std::pair<std::string, std::string> split_at_first_space(const std::string& line) {
1717
auto position = line.find(' ');
1818
if (position == std::string::npos) {
19-
throw std::runtime_error("Could not parse event line: " + line);
19+
throw std::runtime_error("Could not parse line=" + line);
2020
}
2121
return {line.substr(0, position), line.substr(position + 1)};
2222
}
2323

2424
static std::string get_ifname(const std::string& eventprefix) {
2525
if (eventprefix.rfind(HOSTAPD_IFPREFIX) != 0) {
26-
throw std::runtime_error("interface name could not be parsed from event prefix: " + eventprefix);
26+
throw std::runtime_error("Could not parse eventprefix= " + eventprefix);
2727
}
2828
return eventprefix.substr(HOSTAPD_IFPREFIX.size());
2929
}
@@ -38,9 +38,9 @@ ipc::Subscriber::Subscriber(SynchronizedQueue<Event>& queue, const std::chrono::
3838
void ipc::Subscriber::loop(const std::future<void>& future) {
3939
std::string result = socket.send_and_receive({"ATTACH"});
4040
if (result != Socket::HOSTAPD_OK) {
41-
throw std::runtime_error(std::string("could not attach to hostapd: ") + result);
41+
throw std::runtime_error(std::string("Could not attach to hostapd error=") + result);
4242
}
43-
WMLOG(INFO) << "attached to hostapd";
43+
WMLOG(INFO) << "Attached to hostapd.";
4444
while (future.wait_for(std::chrono::seconds(0)) != std::future_status::ready) {
4545
std::string line;
4646
try {
@@ -49,7 +49,9 @@ void ipc::Subscriber::loop(const std::future<void>& future) {
4949
try {
5050
line = socket.send_and_receive({"PING"});
5151
} catch (const TimeoutException& e) {
52-
WMLOG(FATAL) << "timeout in Subscriber::loop_ipc_queue(), hostapd timed out while responding to ping";
52+
WMLOG(FATAL)
53+
<< "Timeout Subscriber::loop_ipc_queue(), hostapd timed out while responding to ping error="
54+
<< e.what();
5355
break;
5456
}
5557
}
@@ -64,7 +66,7 @@ void ipc::Subscriber::loop(const std::future<void>& future) {
6466

6567
std::vector<std::string> interface_names = Configuration::get_instance().socknames;
6668
if (std::find(interface_names.begin(), interface_names.end(), sockname) == interface_names.end()) {
67-
WMLOG(DEBUG) << "Received event on interface that is not configured " << sockname << ": " << event;
69+
WMLOG(DEBUG) << "Not configured event=" << event << " iface=" << sockname;
6870
continue;
6971
}
7072

@@ -76,7 +78,7 @@ void ipc::Subscriber::loop(const std::future<void>& future) {
7678
queue.enqueue(std::make_unique<ConnectEvent>(std::move(station)));
7779
hostapd_connect_counter.Increment();
7880
} catch (const std::runtime_error& e) {
79-
WMLOG(ERROR) << "Unable to create event: " << e.what();
81+
WMLOG(ERROR) << "Unable to create event error=" << e.what();
8082
}
8183
} else if (event.rfind(HOSTAPD_DISCONNECT_STRING) == 0) {
8284
MacAddress station_mac(
@@ -86,11 +88,11 @@ void ipc::Subscriber::loop(const std::future<void>& future) {
8688
queue.enqueue(std::make_unique<DisconnectEvent>(std::move(station)));
8789
hostapd_disconnect_counter.Increment();
8890
} catch (const std::runtime_error& e) {
89-
WMLOG(ERROR) << "Unable to create event: " << e.what();
91+
WMLOG(ERROR) << "Unable to create event error=" << e.what();
9092
}
9193
} else {
9294
hostapd_unknown_counter.Increment();
93-
WMLOG(DEBUG) << "Received unknown event " << event;
95+
WMLOG(DEBUG) << "Received unknown event=" << event;
9496
}
9597
}
9698
}

src/main.cpp

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -36,9 +36,9 @@ void setup_logger() {
3636
} catch (const std::exception& ex) {
3737
WMLOG(FATAL) << typeid(ex).name() << ": " << ex.what();
3838
} catch (...) {
39-
WMLOG(FATAL) << "Error while handling exception: " << typeid(std::current_exception()).name();
39+
WMLOG(FATAL) << "Error while handling exception error=" << typeid(std::current_exception()).name();
4040
}
41-
WMLOG(ERROR) << "errno: " << errno << ": " << std::strerror(errno) << std::endl;
41+
WMLOG(ERROR) << "errno=" << errno << " error=" << std::strerror(errno) << std::endl;
4242
std::abort();
4343
});
4444
el::Configurations default_configuration;
@@ -62,12 +62,12 @@ int main(int argc, char* argv[]) {
6262
if (args.size() >= 2) {
6363
config_path = args[1];
6464
}
65-
WMLOG(INFO) << "wimoved is starting";
65+
WMLOG(INFO) << "Starting wimoved.";
6666
ConfigParser::from_file(config_path).populate_configuration(Configuration::get_instance());
6767
setup_logger();
6868

6969
if (std::signal(SIGINT, handle_signal) == SIG_ERR || std::signal(SIGTERM, handle_signal) == SIG_ERR) {
70-
WMLOG(FATAL) << "could not set up signal handlers " << std::strerror(errno);
70+
WMLOG(FATAL) << "Could not set up signal handlers error=" << std::strerror(errno);
7171
}
7272

7373
SynchronizedQueue<ipc::Event> ipc_queue;

0 commit comments

Comments
 (0)