Skip to content

Commit

Permalink
Merge pull request #3452 from cloudflare/jlee/internal-error-ids
Browse files Browse the repository at this point in the history 
Add "wderrid" error IDs to opaque "internal error" exceptions
  • Loading branch information
@jclee
jclee authored Feb 7, 2025
2 parents ac48549 + 51123f6 commit 6d7815a
Show file tree
Hide file tree
Showing 5 changed files with 198 additions and 10 deletions.
3 changes: 3 additions & 0 deletions src/workerd/jsg/BUILD.bazel
View file
Original file line number Diff line number Diff line change
Expand Up @@ -68,11 +68,13 @@ wd_cc_library(
":observer",
":url",
"//src/workerd/util",
"//src/workerd/util:autogate",
"//src/workerd/util:sentry",
"//src/workerd/util:thread-scopes",
"//src/workerd/util:uuid",
"@capnp-cpp//src/kj",
"@simdutf",
"@ssl",
"@workerd-v8//:v8",
],
)
Expand Down Expand Up @@ -176,6 +178,7 @@ wd_cc_library(
src = f,
deps = [
":jsg",
"//src/workerd/util:autogate",
],
) for f in glob(
["*-test.c++"],
Expand Down
128 changes: 126 additions & 2 deletions src/workerd/jsg/util-test.c++
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,8 @@
#include "jsg-test.h"
#include "jsg.h"

#include <workerd/util/autogate.h>

namespace workerd::jsg::test {
namespace {

Expand Down Expand Up @@ -112,12 +114,21 @@ struct ThrowContext: public ContextGlobalObject {
};
JSG_DECLARE_ISOLATE_TYPE(ThrowIsolate, ThrowContext);

KJ_TEST("throw internal error") {
KJ_TEST("throw internal error without internal-error-id autogate") {
setPredictableModeForTest();
util::Autogate::initAutogateNamesForTest({}); // without internal-error-id autogate
KJ_DEFER(util::Autogate::deinitAutogate());

Evaluator<ThrowContext, ThrowIsolate> e(v8System);
{
KJ_EXPECT_LOG(ERROR, "thrown from throwException");
e.expectEval("throwException()", "throws", "Error: internal error");
}
{
// We also expect the logged internal error to contain the error id.
KJ_EXPECT_LOG(ERROR, "wdErrId = 0123456789abcdefghijklmn");
e.expectEval("throwException()", "throws", "Error: internal error");
}

{
KJ_EXPECT_LOG(ERROR, "thrown from getThrowing");
Expand All @@ -135,6 +146,43 @@ KJ_TEST("throw internal error") {
}
}

KJ_TEST("throw internal error with internal-error-id autogate") {
setPredictableModeForTest();
util::Autogate::initAutogateNamesForTest({"internal-error-id"_kj});
KJ_DEFER(util::Autogate::deinitAutogate());

Evaluator<ThrowContext, ThrowIsolate> e(v8System);
{
KJ_EXPECT_LOG(ERROR, "thrown from throwException");
e.expectEval("throwException()", "throws",
"Error: internal error; reference = 0123456789abcdefghijklmn");
}
{
// We also expect the logged internal error to contain the error id.
KJ_EXPECT_LOG(ERROR, "wdErrId = 0123456789abcdefghijklmn");
e.expectEval("throwException()", "throws",
"Error: internal error; reference = 0123456789abcdefghijklmn");
}

{
KJ_EXPECT_LOG(ERROR, "thrown from getThrowing");
e.expectEval(
"throwing", "throws", "Error: internal error; reference = 0123456789abcdefghijklmn");
}

{
KJ_EXPECT_LOG(ERROR, "thrown from setThrowing");
e.expectEval(
"throwing = 123", "throws", "Error: internal error; reference = 0123456789abcdefghijklmn");
}

{
KJ_EXPECT_LOG(ERROR, "thrown from returnFunctionThatThrows");
e.expectEval("returnFunctionThatThrows(123)(321)", "throws",
"Error: internal error; reference = 0123456789abcdefghijklmn");
}
}

// ========================================================================================

struct TunneledContext: public ContextGlobalObject {
Expand Down Expand Up @@ -261,7 +309,11 @@ struct TunneledContext: public ContextGlobalObject {
};
JSG_DECLARE_ISOLATE_TYPE(TunneledIsolate, TunneledContext);

KJ_TEST("throw tunneled exception") {
KJ_TEST("throw tunneled exception without internal-error-id autogate") {
setPredictableModeForTest();
util::Autogate::initAutogateNamesForTest({}); // without internal-error-id autogate
KJ_DEFER(util::Autogate::deinitAutogate());

Evaluator<TunneledContext, TunneledIsolate> e(v8System);
e.expectEval(
"throwTunneledTypeError()", "throws", "TypeError: thrown from throwTunneledTypeError");
Expand All @@ -279,6 +331,12 @@ KJ_TEST("throw tunneled exception") {
e.expectEval(
"throwTunneledInternalOperationError()", "throws", "OperationError: internal error");
}
{
// We also expect the logged internal error to contain the error id.
KJ_EXPECT_LOG(ERROR, "wdErrId = 0123456789abcdefghijklmn");
e.expectEval(
"throwTunneledInternalOperationError()", "throws", "OperationError: internal error");
}
{
KJ_EXPECT_LOG(ERROR, " jsg.TypeError");
e.expectEval("throwBadTunneledError()", "throws", "Error: internal error");
Expand Down Expand Up @@ -313,6 +371,72 @@ KJ_TEST("throw tunneled exception") {
}
}

KJ_TEST("throw tunneled exception with internal-error-id autogate") {
setPredictableModeForTest();
util::Autogate::initAutogateNamesForTest({"internal-error-id"_kj});
KJ_DEFER(util::Autogate::deinitAutogate());

Evaluator<TunneledContext, TunneledIsolate> e(v8System);
e.expectEval(
"throwTunneledTypeError()", "throws", "TypeError: thrown from throwTunneledTypeError");
e.expectEval("throwTunneledTypeErrorLateColon()", "throws", "TypeError");
e.expectEval("throwTunneledTypeErrorWithExpectation()", "throws",
"TypeError: thrown from throwTunneledTypeErrorWithExpectation");
e.expectEval("throwTunneledOperationError()", "throws",
"OperationError: thrown from throwTunneledOperationError");
e.expectEval("throwTunneledOperationErrorWithoutMessage()", "throws", "OperationError");
e.expectEval("throwTunneledOperationErrorLateColon()", "throws", "OperationError");
e.expectEval("throwTunneledOperationErrorWithExpectation()", "throws",
"OperationError: thrown from throwTunneledOperationErrorWithExpectation");
{
KJ_EXPECT_LOG(ERROR, "thrown from throwTunneledInternalOperationError");
e.expectEval("throwTunneledInternalOperationError()", "throws",
"OperationError: internal error; reference = 0123456789abcdefghijklmn");
}
{
// We also expect the logged internal error to contain the error id.
KJ_EXPECT_LOG(ERROR, "wdErrId = 0123456789abcdefghijklmn");
e.expectEval("throwTunneledInternalOperationError()", "throws",
"OperationError: internal error; reference = 0123456789abcdefghijklmn");
}
{
KJ_EXPECT_LOG(ERROR, " jsg.TypeError");
e.expectEval("throwBadTunneledError()", "throws",
"Error: internal error; reference = 0123456789abcdefghijklmn");
}
{
KJ_EXPECT_LOG(ERROR, "expected s.startsWith(\";\"); jsg.TypeError");
e.expectEval("throwBadTunneledErrorWithExpectation()", "throws",
"Error: internal error; reference = 0123456789abcdefghijklmn");
}
e.expectEval("throwTunneledMacroTypeError()", "throws",
"TypeError: thrown from throwTunneledMacroTypeError");
e.expectEval("throwTunneledMacroTypeErrorWithExpectation()", "throws",
"TypeError: thrown from throwTunneledMacroTypeErrorWithExpectation");
e.expectEval("throwTunneledMacroOperationError()", "throws",
"OperationError: thrown from throwTunneledMacroOperationError");
e.expectEval("throwTunneledMacroOperationErrorWithExpectation()", "throws",
"OperationError: thrown from throwTunneledMacroOperationErrorWithExpectation");
e.expectEval("throwTunneledCompileError()", "throws",
"CompileError: thrown from throwTunneledCompileError");
e.expectEval(
"throwTunneledLinkError()", "throws", "CompileError: thrown from throwTunneledLinkError");
e.expectEval("throwTunneledRuntimeError()", "throws",
"CompileError: thrown from throwTunneledRuntimeError");
e.expectEval(
"throwTunneledDOMException()", "throws", "Some error: thrown from throwTunneledDOMException");
{
KJ_EXPECT_LOG(ERROR, " thrown from throwTunneledInvalidDOMException");
e.expectEval("throwTunneledInvalidDOMException()", "throws",
"Error: internal error; reference = 0123456789abcdefghijklmn");
}
{
KJ_EXPECT_LOG(ERROR, " thrown from throwTunneledGarbledDOMException");
e.expectEval("throwTunneledGarbledDOMException()", "throws",
"Error: internal error; reference = 0123456789abcdefghijklmn");
}
}

KJ_TEST("runTunnelingExceptions") {
Evaluator<TunneledContext, TunneledIsolate> e(v8System);
e.expectEval("throwRetunneledTypeError()", "throws", "TypeError: Dummy error message.");
Expand Down
73 changes: 65 additions & 8 deletions src/workerd/jsg/util.c++
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,8 @@
#include "ser.h"
#include "setup.h"

#include <openssl/rand.h>

#include <kj/debug.h>

#include <cstdlib>
Expand All @@ -15,6 +17,7 @@
#include <cxxabi.h>
#endif

#include <workerd/util/autogate.h>
#include <workerd/util/sentry.h>

namespace workerd::jsg {
Expand Down Expand Up @@ -90,9 +93,52 @@ kj::String typeName(const std::type_info& type) {
return kj::mv(result);
}

namespace {

// For internal errors, we generate an ID to include when rendering user-facing "internal error"
// exceptions and writing internal exception logs, to make it easier to search for logs
// corresponding to "internal error" exceptions reported by users.
//
// We'll use an ID of 24 base-32 encoded characters, just because its relatively simple to
// generate from random bytes. This should give us a value with 120 bits of uniqueness, which is
// about as good as a UUID.
//
// (We're not using base-64 encoding to avoid issues with case insensitive search, as well as
// ensuring that the id is easy to select and copy via double-clicking.)
using InternalErrorId = kj::FixedArray<char, 24>;

constexpr char BASE32_DIGITS[] = "0123456789abcdefghijklmnopqrstuv";

InternalErrorId makeInternalErrorId() {
InternalErrorId id;
if (isPredictableModeForTest()) {
// In testing mode, use content that generates a "0123456789abcdefghijklm" ID:
for (auto i: kj::indices(id)) {
id[i] = i;
}
} else {
KJ_ASSERT(RAND_bytes(id.asPtr().asBytes().begin(), id.size()) == 1);
}
for (auto i: kj::indices(id)) {
id[i] = BASE32_DIGITS[static_cast<unsigned char>(id[i]) % 32];
}
return id;
}

kj::String renderInternalError(InternalErrorId& internalErrorId) {
if (util::Autogate::isEnabled(util::AutogateKey::INTERNAL_ERROR_ID)) {
return kj::str("internal error; reference = ", internalErrorId);
} else {
return kj::str("internal error");
}
}

} // namespace

v8::Local<v8::Value> makeInternalError(v8::Isolate* isolate, kj::StringPtr internalMessage) {
KJ_LOG(ERROR, internalMessage);
return v8::Exception::Error(v8StrIntern(isolate, "internal error"));
auto wdErrId = makeInternalErrorId();
KJ_LOG(ERROR, internalMessage, wdErrId);
return v8::Exception::Error(v8Str(isolate, renderInternalError(wdErrId)));
}

namespace {
Expand Down Expand Up @@ -143,6 +189,8 @@ struct DecodedException {
bool isInternal;
bool isFromRemote;
bool isDurableObjectReset;
// TODO(cleanup): Maybe<> is redundant with isInternal flag field?
kj::Maybe<InternalErrorId> internalErrorId;
};

DecodedException decodeTunneledException(
Expand All @@ -167,15 +215,17 @@ DecodedException decodeTunneledException(
// TODO(someday): Support arbitrary user-defined error types, not just Error?
auto tunneledInfo = tunneledErrorType(internalMessage);

DecodedException result;
auto errorType = tunneledInfo.message;
auto appMessage = [&](kj::StringPtr errorString) -> kj::StringPtr {
auto appMessage = [&](kj::StringPtr errorString) -> kj::ConstString {
if (tunneledInfo.isInternal) {
return "internal error"_kj;
result.internalErrorId = makeInternalErrorId();
return kj::ConstString(renderInternalError(KJ_ASSERT_NONNULL(result.internalErrorId)));
} else {
return trimErrorMessage(errorString);
// .attach() to convert StringPtr to ConstString:
return trimErrorMessage(errorString).attach();
}
};
DecodedException result;
result.isInternal = tunneledInfo.isInternal;
result.isFromRemote = tunneledInfo.isFromRemote;
result.isDurableObjectReset = tunneledInfo.isDurableObjectReset;
Expand Down Expand Up @@ -213,7 +263,9 @@ DecodedException decodeTunneledException(
}
}
// unrecognized exception type
result.handle = v8::Exception::Error(v8StrIntern(isolate, "internal error"));
result.internalErrorId = makeInternalErrorId();
result.handle = v8::Exception::Error(
v8Str(isolate, renderInternalError(KJ_ASSERT_NONNULL(result.internalErrorId))));
result.isInternal = true;
} while (false);
#undef HANDLE_V8_ERROR
Expand All @@ -240,6 +292,7 @@ DecodedException decodeTunneledException(
kj::StringPtr extractTunneledExceptionDescription(kj::StringPtr message) {
auto tunneledError = tunneledErrorType(message);
if (tunneledError.isInternal) {
// TODO(soon): Include an internal error ID in message, and also return the id.
return "Error: internal error";
} else {
return tunneledError.message;
Expand Down Expand Up @@ -271,7 +324,11 @@ v8::Local<v8::Value> makeInternalError(v8::Isolate* isolate, kj::Exception&& exc
// DISCONNECTED exceptions as these are unlikely to represent bugs worth tracking.
if (exception.getType() != kj::Exception::Type::DISCONNECTED &&
!isDoNotLogException(exception.getDescription())) {
LOG_EXCEPTION("jsgInternalError", exception);
// LOG_EXCEPTION("jsgInternalError", ...), but with internal error ID:
auto& e = exception;
constexpr auto sentryErrorContext = "jsgInternalError";
auto& wdErrId = KJ_ASSERT_NONNULL(tunneledException.internalErrorId);
KJ_LOG(ERROR, e, sentryErrorContext, wdErrId);
} else {
KJ_LOG(INFO, exception); // Run with --verbose to see exception logs.
}
Expand Down
2 changes: 2 additions & 0 deletions src/workerd/util/autogate.c++
View file
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,8 @@ kj::StringPtr KJ_STRINGIFY(AutogateKey key) {
return "streaming-tail-workers"_kj;
case AutogateKey::PYTHON_FETCH_INDIVIDUAL_PACKAGES:
return "python-fetch-individual-packages";
case AutogateKey::INTERNAL_ERROR_ID:
return "internal-error-id";
case AutogateKey::NumOfKeys:
KJ_FAIL_ASSERT("NumOfKeys should not be used in getName");
}
Expand Down
2 changes: 2 additions & 0 deletions src/workerd/util/autogate.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,8 @@ enum class AutogateKey {
// Fetches Python packages as individual bundles from GCS instead of using a single big bundle
// embedded in the binary
PYTHON_FETCH_INDIVIDUAL_PACKAGES,
// Adds a "reference" ID to "internal error" exception messages
INTERNAL_ERROR_ID,
NumOfKeys // Reserved for iteration.
};

Expand Down

0 comments on commit 6d7815a

Please sign in to comment.