diff --git a/Development/cmake/NmosCppLibraries.cmake b/Development/cmake/NmosCppLibraries.cmake index d878f4f44..836e0a88f 100644 --- a/Development/cmake/NmosCppLibraries.cmake +++ b/Development/cmake/NmosCppLibraries.cmake @@ -985,6 +985,7 @@ set(NMOS_CPP_BST_HEADERS set(NMOS_CPP_CPPREST_SOURCES cpprest/api_router.cpp + cpprest/basic_utils.cpp cpprest/host_utils.cpp cpprest/http_utils.cpp cpprest/json_escape.cpp diff --git a/Development/cpprest/basic_utils.cpp b/Development/cpprest/basic_utils.cpp new file mode 100644 index 000000000..c71e3395a --- /dev/null +++ b/Development/cpprest/basic_utils.cpp @@ -0,0 +1,46 @@ +#include "cpprest/basic_utils.h" + +#ifdef _WIN32 +#include // for INT_MAX +#include +#endif + +namespace utility +{ + namespace details + { + string_t system_narrow_to_us(const std::string& s) + { + if (s.empty()) return{}; + +#ifdef _WIN32 + // narrow platform strings, e.g. std::system_error::what(), are in the ANSI code page, + // so try that first, unless the ANSI code page is itself UTF-8, which Windows 10 and + // later allow - in that case it would just repeat the decode that has already failed, + // and would substitute U+FFFD for each bad byte, losing the very characters at issue + // MB_ERR_INVALID_CHARS is deliberately not set, since it would reject the bytes we are + // here for, and a best-effort transliteration beats losing the message + if (CP_UTF8 != ::GetACP() && s.size() <= (size_t)INT_MAX) + { + const int size = ::MultiByteToWideChar(CP_ACP, 0, s.data(), (int)s.size(), NULL, 0); + if (0 < size) + { + // utf16string is std::wstring on Windows, so this is the native conversion target + utf16string ws(size, L'\0'); + if (0 < ::MultiByteToWideChar(CP_ACP, 0, s.data(), (int)s.size(), &ws[0], size)) + { + return conversions::to_string_t(std::move(ws)); + } + } + } + // otherwise fall through to Latin-1 +#endif + + // Latin-1 maps each byte to the code point of the same value, so it cannot fail and + // cannot discard anything, which keeps the conversion lossless and reversible + // it also agrees with the Windows Western code page (1252) over 0xA0-0xFF, + // i.e. for the accented letters, so the common case matches on every platform + return conversions::to_string_t(conversions::latin1_to_utf16(s)); + } + } +} diff --git a/Development/cpprest/basic_utils.h b/Development/cpprest/basic_utils.h index ae60371f5..64c99a554 100644 --- a/Development/cpprest/basic_utils.h +++ b/Development/cpprest/basic_utils.h @@ -1,6 +1,7 @@ #ifndef CPPREST_BASIC_UTILS_H #define CPPREST_BASIC_UTILS_H +#include // for std::range_error #include "cpprest/asyncrt_utils.h" // for cpprest/details/basic_types.h and utility::conversions namespace utility @@ -83,6 +84,40 @@ namespace utility return conversions::to_string_t(s); } + namespace details + { + // Decode a narrow string that is not valid UTF-8, using the system narrow encoding + // (the Windows ANSI code page) where there is one, and Latin-1 otherwise + // Latin-1 cannot fail, so neither can this; no input is rejected and nothing is discarded + string_t system_narrow_to_us(const std::string& s); + } + + // Convert a narrow string of uncertain encoding to string_t + // s2us requires valid UTF-8 and throws std::range_error otherwise; use this instead at + // boundaries where the narrow string comes from the platform rather than from this codebase, + // e.g. std::exception::what(), system error messages, or __FILE__, none of which are + // guaranteed to be UTF-8 - on Windows they are typically in the ANSI code page + // Never throws, and never discards a message + inline string_t s2us_lenient(const std::string& s) + { + if (s.empty()) return{}; + try + { + // conversions::to_utf16string is the same decoder that s2us itself uses on a wide + // build, on every platform, so this accepts exactly what s2us accepts and the + // fallback handles exactly what it would have rejected + // note this deliberately discards the result and converts s below, rather than + // converting the decoded value, so that whenever s2us would have succeeded this + // returns precisely what s2us returns, on a narrow build as well as a wide one + (void)conversions::to_utf16string(s); + } + catch (const std::range_error&) + { + return details::system_narrow_to_us(s); + } + return conversions::to_string_t(s); + } + template inline string_t ostringstreamed(const T& value) { diff --git a/Development/cpprest/test/basic_utils_test.cpp b/Development/cpprest/test/basic_utils_test.cpp index 785912e42..603ed1965 100644 --- a/Development/cpprest/test/basic_utils_test.cpp +++ b/Development/cpprest/test/basic_utils_test.cpp @@ -26,3 +26,87 @@ BST_TEST_CASE(testBase64Url) BST_REQUIRE_EQUAL(data, utility::conversions::from_base64url(str)); } } + +//////////////////////////////////////////////////////////////////////////////////////////// +BST_TEST_CASE(testS2usLenientValidUtf8) +{ + // valid UTF-8 must take the fast path, i.e. give exactly what s2us gives, and round-trip + const std::string tests[] = { + "", + "hello", + "\xC3\xBC", // U+00FC latin small letter u with diaeresis + "M\xC3\xBCller", + "\xE2\x82\xAC", // U+20AC euro sign + "\xF0\x9F\x8E\xA5" // U+1F3A5 movie camera + }; + + for (const auto& test : tests) + { + BST_REQUIRE_EQUAL(utility::s2us(test), utility::s2us_lenient(test)); + BST_REQUIRE_EQUAL(test, utility::us2s(utility::s2us_lenient(test))); + } +} + +//////////////////////////////////////////////////////////////////////////////////////////// +BST_TEST_CASE(testS2usLenientInvalidUtf8) +{ + // these are the byte sequences that make s2us throw std::range_error on a wide build, + // e.g. on Windows, where they would escape the async logging worker thread + const std::string tests[] = { + "\xFC", // u with diaeresis in the Windows Western code page, or Latin-1 + "M\xFCller", + "\x80", // continuation byte with no leading byte + "\xC3", // truncated two byte sequence + "\xFF\xFE" + }; + + for (const auto& test : tests) + { + // to_utf16string is the strict decoder that s2us uses on a wide build, on every + // platform, so this asserts the Windows failure mode without needing a wide build + BST_REQUIRE_THROW(utility::conversions::to_utf16string(test), std::range_error); + + utility::string_t converted; + BST_REQUIRE_NO_THROW(converted = utility::s2us_lenient(test)); + + // the message must be preserved, not dropped + BST_REQUIRE(!converted.empty()); + + // and whatever it decoded to must be well-formed, so that it can go into a JSON + // log event and be converted back without throwing + BST_REQUIRE_NO_THROW(utility::conversions::to_utf16string(utility::us2s(converted))); + } + + // empty input is not an error + BST_REQUIRE(utility::s2us_lenient("").empty()); + + // note that the decoder is not a strict UTF-8 validator - it accepts UTF-16 surrogates, + // code points above U+10FFFF and overlong encodings - so these do not take the fallback + // that is deliberate: s2us_lenient differs from s2us only where s2us would have thrown, + // and passes everything else through unchanged + const std::string tolerated[] = { + "\xED\xA0\x80", // a UTF-16 surrogate + "\xF5\x80\x80\x80", // above U+10FFFF + "\xC0\xAF" // overlong encoding of '/' + }; + + for (const auto& test : tolerated) + { + BST_REQUIRE_NO_THROW(utility::conversions::to_utf16string(test)); + BST_REQUIRE_EQUAL(utility::s2us(test), utility::s2us_lenient(test)); + } +} + +//////////////////////////////////////////////////////////////////////////////////////////// +BST_TEST_CASE(testS2usLenientLatin1Fallback) +{ +#ifndef _WIN32 + // where there is no ANSI code page, the fallback is Latin-1, which maps each byte to the + // code point of the same value; the Windows Western code page (1252) agrees over 0xA0-0xFF, + // so the accented letters come out the same on either + // this is not asserted on Windows, where the ANSI code page is a machine setting and a + // double byte code page, e.g. 932, treats 0xFC as a leading byte instead + BST_REQUIRE_EQUAL(utility::s2us("\xC3\xBC"), utility::s2us_lenient("\xFC")); + BST_REQUIRE_EQUAL(utility::s2us("M\xC3\xBCller"), utility::s2us_lenient("M\xFCller")); +#endif +} diff --git a/Development/nmos/api_utils.cpp b/Development/nmos/api_utils.cpp index a4fa44be0..edcb605ff 100644 --- a/Development/nmos/api_utils.cpp +++ b/Development/nmos/api_utils.cpp @@ -616,7 +616,8 @@ namespace nmos // set up a standard NMOS error response, using the default reason phrase and the specified debug information void set_error_reply(web::http::http_response& res, web::http::status_code code, const std::exception& debug) { - set_error_reply(res, code, {}, utility::s2us(debug.what())); + // what() is a narrow platform string with no UTF-8 guarantee + set_error_reply(res, code, {}, utility::s2us_lenient(debug.what())); } // add handler to set appropriate response headers, and error response body if indicated - call this only after adding all others! @@ -863,7 +864,8 @@ namespace nmos if (error.value != nmos::experimental::authorization_error::without_authentication) { utility::string_t error_string = { (error.value == nmos::experimental::authorization_error::insufficient_scope) ? web::http::oauth2::experimental::resource_server_errors::insufficient_scope.name : web::http::oauth2::experimental::resource_server_errors::invalid_token.name }; - error_description = utility::s2us(error.message); + // the message originates from std::exception::what(), so may not be UTF-8 + error_description = utility::s2us_lenient(error.message); auth_params += U(",error=") + error_string + U(",error_description=") + error_description; } @@ -880,7 +882,7 @@ namespace nmos res.headers().add(web::http::header_names::retry_after, retry_after); } - nmos::set_error_reply(res, status_code, utility::s2us(error.message)); + nmos::set_error_reply(res, status_code, utility::s2us_lenient(error.message)); } } } diff --git a/Development/nmos/authorization_redirect_api.cpp b/Development/nmos/authorization_redirect_api.cpp index 22290985f..d0993a01c 100644 --- a/Development/nmos/authorization_redirect_api.cpp +++ b/Development/nmos/authorization_redirect_api.cpp @@ -44,7 +44,8 @@ namespace nmos inline authorization_flow_response make_authorization_flow_error_response(web::http::status_code code, const std::exception& debug) { - return make_authorization_flow_error_response(code, {}, utility::s2us(debug.what())); + // what() is a narrow platform string with no UTF-8 guarantee + return make_authorization_flow_error_response(code, {}, utility::s2us_lenient(debug.what())); } void process_error_response(const web::uri& redirected_uri, const utility::string_t& response_type, const utility::string_t& state) diff --git a/Development/nmos/channelmapping_api.cpp b/Development/nmos/channelmapping_api.cpp index 0439d8a12..5f72ee115 100644 --- a/Development/nmos/channelmapping_api.cpp +++ b/Development/nmos/channelmapping_api.cpp @@ -84,7 +84,8 @@ namespace nmos inline channelmapping_activation_post_response make_channelmapping_activation_post_error_response(web::http::status_code code, const std::exception& debug) { - return make_channelmapping_activation_post_error_response(code, {}, utility::s2us(debug.what())); + // what() is a narrow platform string with no UTF-8 guarantee + return make_channelmapping_activation_post_error_response(code, {}, utility::s2us_lenient(debug.what())); } inline utility::string_t make_channelmapping_input_error(const nmos::channelmapping_id& input_id) diff --git a/Development/nmos/connection_api.cpp b/Development/nmos/connection_api.cpp index b0acc28c0..22d85af40 100644 --- a/Development/nmos/connection_api.cpp +++ b/Development/nmos/connection_api.cpp @@ -447,7 +447,8 @@ namespace nmos inline connection_resource_patch_response make_connection_resource_patch_error_response(web::http::status_code code, const std::exception& debug) { - return make_connection_resource_patch_error_response(code, {}, utility::s2us(debug.what())); + // what() is a narrow platform string with no UTF-8 guarantee + return make_connection_resource_patch_error_response(code, {}, utility::s2us_lenient(debug.what())); } // Basic theory of implementation of PATCH /staged diff --git a/Development/nmos/control_protocol_ws_api.cpp b/Development/nmos/control_protocol_ws_api.cpp index 855d09026..b1517afdc 100644 --- a/Development/nmos/control_protocol_ws_api.cpp +++ b/Development/nmos/control_protocol_ws_api.cpp @@ -369,7 +369,7 @@ namespace nmos resources.modify(grain, [&](nmos::resource& grain) { web::json::push_back(nmos::fields::message_grain_data(grain.data), - nc::make_error_message({ nc_method_status::bad_command_format }, utility::s2us(e.what()))); + nc::make_error_message({ nc_method_status::bad_command_format }, utility::s2us_lenient(e.what()))); grain.updated = strictly_increasing_update(resources); }); @@ -381,7 +381,7 @@ namespace nmos resources.modify(grain, [&](nmos::resource& grain) { web::json::push_back(nmos::fields::message_grain_data(grain.data), - nc::make_error_message({ nc_method_status::bad_command_format }, utility::s2us(std::string("Unexpected exception while handing control protocol command : ") + e.what()))); + nc::make_error_message({ nc_method_status::bad_command_format }, utility::s2us_lenient(std::string("Unexpected exception while handing control protocol command : ") + e.what()))); grain.updated = strictly_increasing_update(resources); }); diff --git a/Development/nmos/log_gate.h b/Development/nmos/log_gate.h index 8097af79d..e86f17ade 100644 --- a/Development/nmos/log_gate.h +++ b/Development/nmos/log_gate.h @@ -133,19 +133,38 @@ namespace nmos { auto lock = model.write_lock(); - auto categories = nmos::get_categories_stash(message.stream()); + // this runs on the async logging worker thread, and slog's message_service::run only + // catches its own stopped_exception, so anything else escaping here would propagate out + // of the thread function and terminate the process - a last resort, since a failure to + // log must never take down the application; the encoding boundaries that could + // realistically throw are handled in json_from_message with utility::s2us_lenient + try + { + auto categories = nmos::get_categories_stash(message.stream()); + + if (pertinent(message.level()) && pertinent(categories)) + { + error_log << details::error_log_format(message); + } + + if (categories.end() != boost::range::find(categories, nmos::categories::access)) + { + access_log << nmos::common_log_format(message); + } - if (pertinent(message.level()) && pertinent(categories)) + nmos::experimental::insert_log_event(model.events, message, generate_id(), nmos::experimental::fields::logging_limit(model.settings)); + } + catch (const std::exception& e) { - error_log << details::error_log_format(message); + // report on the error log directly rather than via the gate, which would re-enter here + // and guard that too, since the error log is itself a plausible source of the error, + // and throwing from a handler here would defeat the point of catching at all + try { error_log << "Error while logging: " << e.what() << std::endl; } catch (...) {} } - - if (categories.end() != boost::range::find(categories, nmos::categories::access)) + catch (...) { - access_log << nmos::common_log_format(message); + try { error_log << "Unexpected error while logging" << std::endl; } catch (...) {} } - - nmos::experimental::insert_log_event(model.events, message, generate_id(), nmos::experimental::fields::logging_limit(model.settings)); } mutable slog::async_log_service async_service; diff --git a/Development/nmos/log_model.cpp b/Development/nmos/log_model.cpp index 4a8cf531f..9097f9a95 100644 --- a/Development/nmos/log_model.cpp +++ b/Development/nmos/log_model.cpp @@ -27,11 +27,15 @@ namespace nmos // hmm, could be good to provide a log/settings option to redact thread_id and/or source_location? { U("thread_id"), ostringstreamed(message.thread_id()) }, { U("source_location"), web::json::value_of({ - { U("file"), utility::s2us(message.file()) }, + // __FILE__ and __FUNCTION__ are narrow platform strings, so may not be UTF-8 + { U("file"), utility::s2us_lenient(message.file()) }, { U("line"), message.line() }, - { U("function"), utility::s2us(message.function()) } + { U("function"), utility::s2us_lenient(message.function()) } }, true) }, - { U("message"), utility::s2us(message.str()) }, + // log messages may contain arbitrary narrow text, e.g. from std::exception::what(), + // which carries no UTF-8 guarantee; s2us would throw std::range_error on such bytes, + // and this runs on the async logging worker thread where that would terminate the app + { U("message"), utility::s2us_lenient(message.str()) }, { U("id"), id } }, true); @@ -43,7 +47,7 @@ namespace nmos const auto route_parameters = nmos::get_route_parameters_stash(message.stream()); if (!route_parameters.empty()) json_message[U("route_parameters")] = web::json::value_from_fields(route_parameters); const auto categories = nmos::get_categories_stash(message.stream()); - if (!categories.empty()) json_message[U("tags")][U("category")] = web::json::value_from_elements(categories | boost::adaptors::transformed(utility::s2us)); + if (!categories.empty()) json_message[U("tags")][U("category")] = web::json::value_from_elements(categories | boost::adaptors::transformed(utility::s2us_lenient)); return json_message; } diff --git a/Development/nmos/test/log_gate_test.cpp b/Development/nmos/test/log_gate_test.cpp index 0b2ca994b..280f1ca81 100644 --- a/Development/nmos/test/log_gate_test.cpp +++ b/Development/nmos/test/log_gate_test.cpp @@ -3,6 +3,7 @@ #include #include "bst/test/test.h" +#include "cpprest/basic_utils.h" // for utility::us2s namespace { @@ -85,3 +86,42 @@ BST_TEST_CASE(testLogGatePertinentCategories) BST_REQUIRE(!gate.pertinent(access)); BST_REQUIRE(gate.pertinent(send_query_ws_events)); } + +//////////////////////////////////////////////////////////////////////////////////////////// +BST_TEST_CASE(testInsertLogEventNonUtf8) +{ + // this covers the path that crashed: a log message containing locale-dependent narrow + // bytes, e.g. from std::exception::what(), being serialized to JSON on the async logging + // worker thread, where utility::s2us threw std::range_error and nothing caught it + nmos::experimental::log_events events; + + // 0xFC is u with diaeresis in the Windows Western code page, and is not valid UTF-8 + const slog::async_log_message message("M\xFCller.cpp", 42, "f\xFCnf", slog::severities::error, "caf\xFC"); + + BST_REQUIRE_NO_THROW(nmos::experimental::insert_log_event(events, message, U("42"))); + BST_REQUIRE_EQUAL(size_t(1), events.size()); + + const auto& data = events.front().data; + + // the message and source location are preserved, not dropped or emptied + BST_REQUIRE(!data.at(U("message")).as_string().empty()); + BST_REQUIRE(!data.at(U("source_location")).at(U("file")).as_string().empty()); + BST_REQUIRE(!data.at(U("source_location")).at(U("function")).as_string().empty()); + + // and the event is well-formed, i.e. the Logging API can serialize and return it + BST_REQUIRE_NO_THROW(web::json::value::parse(data.serialize())); + + // each converted field must be valid UTF-8, which is what makes the JSON well-formed + // to_utf16string is the strict decoder, so this asserts the fix on a narrow build too, + // where s2us is a pass-through and would otherwise have let the invalid bytes through + for (const auto& field : { data.at(U("message")), data.at(U("source_location")).at(U("file")), data.at(U("source_location")).at(U("function")) }) + { + BST_REQUIRE_NO_THROW(utility::conversions::to_utf16string(utility::us2s(field.as_string()))); + } + + // valid UTF-8 is unaffected, i.e. it still arrives exactly as logged + const slog::async_log_message utf8_message("test.cpp", 42, "test", slog::severities::error, "caf\xC3\xA9"); + BST_REQUIRE_NO_THROW(nmos::experimental::insert_log_event(events, utf8_message, U("43"))); + BST_REQUIRE_EQUAL(size_t(2), events.size()); + BST_REQUIRE_EQUAL(utility::s2us("caf\xC3\xA9"), events.front().data.at(U("message")).as_string()); +}