Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Censor write only variables logging and added a new callback to sanitize any logging that would be passed to the existing message_callback #911

Open
wants to merge 5 commits into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
5 changes: 3 additions & 2 deletions include/ocpp/common/ocpp_logging.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -60,6 +60,7 @@ class MessageLogging {
std::filesystem::path security_log_file;
std::ofstream security_log_os;
std::mutex output_file_mutex;
std::function<std::string(const std::string& message)> sanitize_message_callback;
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

As discussed in the last WG meeting, lets drop this callback from this PR and just merge the write only variable logging changes. I'll follow up with a generic solution

std::function<void(const std::string& message, MessageDirection direction)> message_callback;
std::function<void(LogRotationStatus status)> status_callback;
std::map<std::string, std::string> lookup_map;
Expand Down Expand Up @@ -113,14 +114,14 @@ class MessageLogging {
explicit MessageLogging(
bool log_messages, const std::string& message_log_path, const std::string& output_file_name,
bool log_to_console, bool detailed_log_to_console, bool log_to_file, bool log_to_html, bool log_security,
bool session_logging,
bool session_logging, std::function<std::string(const std::string& message)> sanitize_message_callback,
std::function<void(const std::string& message, MessageDirection direction)> message_callback);

/// \brief Creates a new MessageLogging object with the provided configuration and enabled log rotation
explicit MessageLogging(
bool log_messages, const std::string& message_log_path, const std::string& output_file_name,
bool log_to_console, bool detailed_log_to_console, bool log_to_file, bool log_to_html, bool log_security,
bool session_logging,
bool session_logging, std::function<std::string(const std::string& message)> sanitize_message_callback,
std::function<void(const std::string& message, MessageDirection direction)> message_callback,
LogRotationConfig log_rotation_config, std::function<void(LogRotationStatus status)> status_callback);
~MessageLogging();
Expand Down
6 changes: 5 additions & 1 deletion include/ocpp/v201/charge_point_callbacks.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -97,7 +97,11 @@ struct Callbacks {
std::optional<ConfigureNetworkConnectionProfileCallback> configure_network_connection_profile_callback;
std::optional<std::function<void(const ocpp::DateTime& currentTime)>> time_sync_callback;

/// \brief callback to be called to congfigure ocpp message logging
/// \brief callback to be called to censor or sanitize any logging (to prevent secrets begin logged in plain-text
/// for example) before ocpp_messages_callback is invoked
std::optional<std::function<std::string(const std::string& message)>> sanitize_ocpp_messages_callback;

/// \brief callback to be called to configure ocpp message logging
std::optional<std::function<void(const std::string& message, MessageDirection direction)>> ocpp_messages_callback;

///
Expand Down
8 changes: 8 additions & 0 deletions include/ocpp/v201/device_model.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -209,6 +209,14 @@ class DeviceModel {
}
}

/// \brief Get the mutability for the given component, variable and attribute_enum
/// \param component_id
/// \param variable_id
/// \param attribute_enum
/// \return The mutability of the given component variable, else std::nullopt
std::optional<MutabilityEnum> get_mutability(const Component& component_id, const Variable& variable,
const AttributeEnum& attribute_enum);

/// \brief Sets the variable_id attribute \p value specified by \p component_id , \p variable_id and \p
/// attribute_enum
/// \param component_id
Expand Down
25 changes: 18 additions & 7 deletions lib/ocpp/common/ocpp_logging.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@ namespace ocpp {
MessageLogging::MessageLogging(
bool log_messages, const std::string& message_log_path, const std::string& output_file_name, bool log_to_console,
bool detailed_log_to_console, bool log_to_file, bool log_to_html, bool log_security, bool session_logging,
std::function<std::string(const std::string& message)> sanitize_message_callback,
std::function<void(const std::string& message, MessageDirection direction)> message_callback) :
log_messages(log_messages),
message_log_path(message_log_path),
Expand All @@ -27,6 +28,7 @@ MessageLogging::MessageLogging(
log_to_html(log_to_html),
log_security(log_security),
session_logging(session_logging),
sanitize_message_callback(sanitize_message_callback),
message_callback(message_callback),
rotate_logs(false),
date_suffix(false),
Expand All @@ -38,6 +40,7 @@ MessageLogging::MessageLogging(
MessageLogging::MessageLogging(
bool log_messages, const std::string& message_log_path, const std::string& output_file_name, bool log_to_console,
bool detailed_log_to_console, bool log_to_file, bool log_to_html, bool log_security, bool session_logging,
std::function<std::string(const std::string& message)> sanitize_message_callback,
std::function<void(const std::string& message, MessageDirection direction)> message_callback,
LogRotationConfig log_rotation_config, std::function<void(LogRotationStatus status)> status_callback) :
log_messages(log_messages),
Expand All @@ -49,6 +52,7 @@ MessageLogging::MessageLogging(
log_to_html(log_to_html),
log_security(log_security),
session_logging(session_logging),
sanitize_message_callback(sanitize_message_callback),
message_callback(message_callback),
rotate_logs(true),
date_suffix(log_rotation_config.date_suffix),
Expand All @@ -66,6 +70,9 @@ void MessageLogging::initialize() {
if (this->log_to_console) {
EVLOG_info << "Logging OCPP messages to console";
}
if (this->sanitize_message_callback != nullptr) {
EVLOG_info << "Sanitizing OCPP messages before passing them to the logging callback";
}
if (this->message_callback != nullptr) {
EVLOG_info << "Logging OCPP messages to callback";
}
Expand Down Expand Up @@ -274,29 +281,33 @@ MessageLogging::~MessageLogging() {
}

void MessageLogging::charge_point(const std::string& message_type, const std::string& json_str) {
const std::string& effective_json_str =
(this->sanitize_message_callback != nullptr) ? this->sanitize_message_callback(json_str) : json_str;
if (this->message_callback != nullptr) {
this->message_callback(json_str, MessageDirection::ChargingStationToCSMS);
this->message_callback(effective_json_str, MessageDirection::ChargingStationToCSMS);
}
auto formatted = format_message(message_type, json_str);
auto formatted = format_message(message_type, effective_json_str);
log_output(0, formatted.message_type, formatted.message);
if (this->session_logging) {
std::scoped_lock lock(this->session_id_logging_mutex);
for (auto const& [session_id, logging] : this->session_id_logging) {
logging->charge_point(message_type, json_str);
logging->charge_point(message_type, effective_json_str);
}
}
}

void MessageLogging::central_system(const std::string& message_type, const std::string& json_str) {
const std::string& effective_json_str =
(this->sanitize_message_callback != nullptr) ? this->sanitize_message_callback(json_str) : json_str;
if (this->message_callback != nullptr) {
this->message_callback(json_str, MessageDirection::CSMSToChargingStation);
this->message_callback(effective_json_str, MessageDirection::ChargingStationToCSMS);
}
auto formatted = format_message(message_type, json_str);
auto formatted = format_message(message_type, effective_json_str);
log_output(1, formatted.message_type, formatted.message);
if (this->session_logging) {
std::scoped_lock lock(this->session_id_logging_mutex);
for (auto const& [session_id, logging] : this->session_id_logging) {
logging->central_system(message_type, json_str);
logging->central_system(message_type, effective_json_str);
}
}
}
Expand Down Expand Up @@ -407,7 +418,7 @@ FormattedMessageWithType MessageLogging::format_message(const std::string& messa
void MessageLogging::start_session_logging(const std::string& session_id, const std::string& log_path) {
std::scoped_lock lock(this->session_id_logging_mutex);
this->session_id_logging[session_id] = std::make_shared<ocpp::MessageLogging>(
true, log_path, "incomplete-ocpp", false, false, false, true, false, false, nullptr);
true, log_path, "incomplete-ocpp", false, false, false, true, false, false, nullptr, nullptr);
}

void MessageLogging::stop_session_logging(const std::string& session_id) {
Expand Down
1 change: 0 additions & 1 deletion lib/ocpp/common/websocket/websocket_libwebsockets.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -1490,7 +1490,6 @@ void WebsocketLibwebsockets::on_conn_message(std::string&& message) {
return;
}

EVLOG_debug << "Received message over TLS websocket polling for process: " << message;
recv_message_queue.push(std::move(message));
}

Expand Down
4 changes: 2 additions & 2 deletions lib/ocpp/v16/charge_point_impl.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -74,7 +74,7 @@ ChargePointImpl::ChargePointImpl(const std::string& config, const fs::path& shar
if (this->configuration->getLogRotation()) {
this->logging = std::make_shared<ocpp::MessageLogging>(
this->configuration->getLogMessages(), this->message_log_path, "libocpp_16", log_to_console,
detailed_log_to_console, log_to_file, log_to_html, log_security, session_logging, nullptr,
detailed_log_to_console, log_to_file, log_to_html, log_security, session_logging, nullptr, nullptr,
ocpp::LogRotationConfig(this->configuration->getLogRotationDateSuffix(),
this->configuration->getLogRotationMaximumFileSize(),
this->configuration->getLogRotationMaximumFileCount()),
Expand All @@ -88,7 +88,7 @@ ChargePointImpl::ChargePointImpl(const std::string& config, const fs::path& shar
} else {
this->logging = std::make_shared<ocpp::MessageLogging>(
this->configuration->getLogMessages(), this->message_log_path, DateTime().to_rfc3339(), log_to_console,
detailed_log_to_console, log_to_file, log_to_html, log_security, session_logging, nullptr);
detailed_log_to_console, log_to_file, log_to_html, log_security, session_logging, nullptr, nullptr);
}

this->boot_notification_timer =
Expand Down
24 changes: 20 additions & 4 deletions lib/ocpp/v201/charge_point.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -518,7 +518,9 @@ void ChargePoint::configure_message_logging_format(const std::string& message_lo
bool log_to_html = log_formats.find("html") != log_formats.npos;
bool log_security = log_formats.find("security") != log_formats.npos;
bool session_logging = log_formats.find("session_logging") != log_formats.npos;
bool sanitize_callback = log_formats.find("sanitize") != log_formats.npos;
bool message_callback = log_formats.find("callback") != log_formats.npos;
std::function<std::string(const std::string& message)> sanitize_ocpp_messages_callback = nullptr;
std::function<void(const std::string& message, MessageDirection direction)> logging_callback = nullptr;
bool log_rotation =
this->device_model->get_optional_value<bool>(ControllerComponentVariables::LogRotation).value_or(false);
Expand All @@ -532,14 +534,18 @@ void ChargePoint::configure_message_logging_format(const std::string& message_lo
this->device_model->get_optional_value<uint64_t>(ControllerComponentVariables::LogRotationMaximumFileCount)
.value_or(0);

if (sanitize_callback) {
sanitize_ocpp_messages_callback = this->callbacks.sanitize_ocpp_messages_callback.value_or(nullptr);
}

if (message_callback) {
logging_callback = this->callbacks.ocpp_messages_callback.value_or(nullptr);
}

if (log_rotation) {
this->logging = std::make_shared<ocpp::MessageLogging>(
!log_formats.empty(), message_log_path, "libocpp_201", log_to_console, detailed_log_to_console, log_to_file,
log_to_html, log_security, session_logging, logging_callback,
log_to_html, log_security, session_logging, sanitize_ocpp_messages_callback, logging_callback,
ocpp::LogRotationConfig(log_rotation_date_suffix, log_rotation_maximum_file_size,
log_rotation_maximum_file_count),
[this](ocpp::LogRotationStatus status) {
Expand All @@ -553,7 +559,7 @@ void ChargePoint::configure_message_logging_format(const std::string& message_lo
} else {
this->logging = std::make_shared<ocpp::MessageLogging>(
!log_formats.empty(), message_log_path, DateTime().to_rfc3339(), log_to_console, detailed_log_to_console,
log_to_file, log_to_html, log_security, session_logging, logging_callback);
log_to_file, log_to_html, log_security, session_logging, sanitize_ocpp_messages_callback, logging_callback);
}
}

Expand Down Expand Up @@ -1816,8 +1822,18 @@ void ChargePoint::handle_variables_changed(const std::map<SetVariableData, SetVa
// iterate over set_variable_results
for (const auto& [set_variable_data, set_variable_result] : set_variable_results) {
if (set_variable_result.attributeStatus == SetVariableStatusEnum::Accepted) {
EVLOG_info << set_variable_data.component.name << ":" << set_variable_data.variable.name << " changed to "
<< set_variable_data.attributeValue.get();
std::optional<MutabilityEnum> mutability =
this->device_model->get_mutability(set_variable_data.component, set_variable_data.variable,
set_variable_data.attributeType.value_or(AttributeEnum::Actual));
// If a nullopt is returned for whatever reason, assume it's write-only to prevent leaking secrets
if (!mutability.has_value() || (mutability.value() == MutabilityEnum::WriteOnly)) {
EVLOG_info << "Write-only " << set_variable_data.component.name << ":"
<< set_variable_data.variable.name << " changed";
} else {
EVLOG_info << set_variable_data.component.name << ":" << set_variable_data.variable.name
<< " changed to " << set_variable_data.attributeValue.get();
}

// handles required behavior specified within OCPP2.0.1 (e.g. reconnect when BasicAuthPassword has changed)
this->handle_variable_changed(set_variable_data);
// notifies libocpp user application that a variable has changed
Expand Down
2 changes: 2 additions & 0 deletions lib/ocpp/v201/charge_point_callbacks.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,8 @@ bool Callbacks::all_callbacks_valid(std::shared_ptr<DeviceModel> device_model) c
this->configure_network_connection_profile_callback.value() != nullptr) and
(!this->time_sync_callback.has_value() or this->time_sync_callback.value() != nullptr) and
(!this->boot_notification_callback.has_value() or this->boot_notification_callback.value() != nullptr) and
(!this->sanitize_ocpp_messages_callback.has_value() or
this->sanitize_ocpp_messages_callback.value() != nullptr) and
(!this->ocpp_messages_callback.has_value() or this->ocpp_messages_callback.value() != nullptr) and
(!this->cs_effective_operative_status_changed_callback.has_value() or
this->cs_effective_operative_status_changed_callback.value() != nullptr) and
Expand Down
10 changes: 10 additions & 0 deletions lib/ocpp/v201/device_model.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -249,6 +249,16 @@ GetVariableStatusEnum DeviceModel::request_value_internal(const Component& compo
return GetVariableStatusEnum::Accepted;
}

std::optional<MutabilityEnum> DeviceModel::get_mutability(const Component& component, const Variable& variable,
const AttributeEnum& attribute_enum) {
const auto attribute = this->device_model->get_variable_attribute(component, variable, attribute_enum);
if (!attribute.has_value()) {
return std::nullopt;
}

return attribute.value().mutability.value();
}

SetVariableStatusEnum DeviceModel::set_value(const Component& component, const Variable& variable,
const AttributeEnum& attribute_enum, const std::string& value,
const std::string& source, bool allow_read_only) {
Expand Down