1
0
mirror of https://github.com/pgbackrest/pgbackrest.git synced 2025-03-05 15:05:48 +02:00

Fix reliability of error reporting from local/remote processes.

Asserts were only only reported on stderr rather than being returned through the protocol layer.  This did not appear to be very reliable.

Instead, report the assert through the protocol layer like any other error.  Add a stack trace if an assert error or debug logging is enabled.
This commit is contained in:
David Steele 2019-04-18 10:36:21 -04:00
parent 281d2848b9
commit b960919cf7
7 changed files with 39 additions and 19 deletions

View File

@ -15,6 +15,10 @@
<release date="XXXX-XX-XX" version="2.13dev" title="UNDER DEVELOPMENT">
<release-core-list>
<release-bug-list>
<release-item>
<p>Fix reliability of error reporting from <cmd>local</cmd>/<cmd>remote</cmd> processes.</p>
</release-item>
<release-item>
<p>Fix <proper>Posix</proper>/<proper>CIFS</proper> error messages reporting the wrong filename on write/sync/close.</p>
</release-item>

View File

@ -57,7 +57,7 @@ cmdRemote(int handleRead, int handleWrite)
}
CATCH_ANY()
{
protocolServerError(server, errorCode(), STR(errorMessage()));
protocolServerError(server, errorCode(), STR(errorMessage()), STR(errorStackTrace()));
}
TRY_END();

View File

@ -21,6 +21,7 @@ STRING_EXTERN(PROTOCOL_COMMAND_NOOP_STR, PROTOCOL_COM
STRING_EXTERN(PROTOCOL_COMMAND_EXIT_STR, PROTOCOL_COMMAND_EXIT);
STRING_EXTERN(PROTOCOL_ERROR_STR, PROTOCOL_ERROR);
STRING_EXTERN(PROTOCOL_ERROR_STACK_STR, PROTOCOL_ERROR_STACK);
STRING_EXTERN(PROTOCOL_OUTPUT_STR, PROTOCOL_OUTPUT);
@ -140,11 +141,14 @@ protocolClientReadOutput(ProtocolClient *this, bool outputRequired)
if (error != NULL)
{
const ErrorType *type = errorTypeFromCode(varIntForce(error));
const String *message = varStr(kvGet(responseKv, VARSTR(PROTOCOL_OUTPUT_STR)));
const String *stack = varStr(kvGet(responseKv, VARSTR(PROTOCOL_ERROR_STACK_STR)));
THROWP_FMT(
errorTypeFromCode(varIntForce(error)), "%s: %s", strPtr(this->errorPrefix),
message == NULL ? "no details available" : strPtr(message));
type, "%s: %s%s", strPtr(this->errorPrefix), message == NULL ? "no details available" : strPtr(message),
type == &AssertError || logWill(logLevelDebug) ?
(stack == NULL ? "\nno stack trace available" : strPtr(strNewFmt("\n%s", strPtr(stack)))) : "");
}
// Get output

View File

@ -30,6 +30,8 @@ Constants
#define PROTOCOL_ERROR "err"
STRING_DECLARE(PROTOCOL_ERROR_STR);
#define PROTOCOL_ERROR_STACK "errStack"
STRING_DECLARE(PROTOCOL_ERROR_STACK_STR);
#define PROTOCOL_OUTPUT "out"
STRING_DECLARE(PROTOCOL_OUTPUT_STR);

View File

@ -95,21 +95,24 @@ protocolServerHandlerAdd(ProtocolServer *this, ProtocolServerProcessHandler hand
Return an error
***********************************************************************************************************************************/
void
protocolServerError(ProtocolServer *this, int code, const String *message)
protocolServerError(ProtocolServer *this, int code, const String *message, const String *stack)
{
FUNCTION_LOG_BEGIN(logLevelTrace);
FUNCTION_LOG_PARAM(PROTOCOL_SERVER, this);
FUNCTION_LOG_PARAM(INT, code);
FUNCTION_LOG_PARAM(STRING, message);
FUNCTION_LOG_PARAM(STRING, stack);
FUNCTION_LOG_END();
ASSERT(this != NULL);
ASSERT(code != 0);
ASSERT(message != NULL);
ASSERT(stack != NULL);
KeyValue *error = kvNew();
kvPut(error, VARSTR(PROTOCOL_ERROR_STR), VARINT(errorCode()));
kvPut(error, VARSTR(PROTOCOL_OUTPUT_STR), VARSTRZ(errorMessage()));
kvPut(error, VARSTR(PROTOCOL_ERROR_STR), VARINT(code));
kvPut(error, VARSTR(PROTOCOL_OUTPUT_STR), VARSTR(message));
kvPut(error, VARSTR(PROTOCOL_ERROR_STACK_STR), VARSTR(stack));
ioWriteLine(this->write, kvToJson(error, 0));
ioWriteFlush(this->write);
@ -169,14 +172,10 @@ protocolServerProcess(ProtocolServer *this)
}
MEM_CONTEXT_TEMP_END();
}
// Asserts are thrown so a stack trace will be output to aid in debugging
CATCH(AssertError)
{
RETHROW();
}
CATCH_ANY()
{
protocolServerError(this, errorCode(), STR(errorMessage()));
// Report error to the client
protocolServerError(this, errorCode(), STR(errorMessage()), STR(errorStackTrace()));
}
TRY_END();
}

View File

@ -25,7 +25,7 @@ ProtocolServer *protocolServerNew(const String *name, const String *service, IoR
/***********************************************************************************************************************************
Functions
***********************************************************************************************************************************/
void protocolServerError(ProtocolServer *this, int code, const String *message);
void protocolServerError(ProtocolServer *this, int code, const String *message, const String *stack);
void protocolServerProcess(ProtocolServer *this);
void protocolServerResponse(ProtocolServer *this, const Variant *output);
void protocolServerHandlerAdd(ProtocolServer *this, ProtocolServerProcessHandler handler);

View File

@ -5,6 +5,7 @@ Test Protocol
#include "common/io/handleWrite.h"
#include "common/io/bufferRead.h"
#include "common/io/bufferWrite.h"
#include "common/regExp.h"
#include "storage/storage.h"
#include "storage/driver/posix/storage.h"
#include "version.h"
@ -319,7 +320,9 @@ testRun(void)
TEST_RESULT_PTR(protocolClientIoWrite(client), client->write, "get write io");
// Throw errors
TEST_ERROR(protocolClientNoOp(client), AssertError, "raised from test client: sample error message");
TEST_ERROR(
protocolClientNoOp(client), AssertError,
"raised from test client: sample error message\nno stack trace available");
TEST_ERROR(protocolClientNoOp(client), UnknownError, "raised from test client: no details available");
TEST_ERROR(protocolClientNoOp(client), AssertError, "no output required by command");
@ -366,18 +369,27 @@ testRun(void)
TEST_RESULT_STR(strPtr(ioReadLine(read)), "{}", "noop result");
// Invalid command
KeyValue *result = NULL;
TEST_RESULT_VOID(ioWriteLine(write, strNew("{\"cmd\":\"bogus\"}")), "write bogus");
TEST_RESULT_VOID(ioWriteFlush(write), "flush bogus");
TEST_RESULT_STR(strPtr(ioReadLine(read)), "{\"err\":39,\"out\":\"invalid command 'bogus'\"}", "bogus error");
TEST_ASSIGN(result, varKv(jsonToVar(ioReadLine(read))), "parse error result");
TEST_RESULT_INT(varIntForce(kvGet(result, VARSTRDEF("err"))), 39, " check code");
TEST_RESULT_STR(strPtr(varStr(kvGet(result, VARSTRDEF("out")))), "invalid command 'bogus'", " check message");
TEST_RESULT_BOOL(kvGet(result, VARSTRDEF("errStack")) != NULL, true, " check stack exists");
// Simple request
TEST_RESULT_VOID(ioWriteLine(write, strNew("{\"cmd\":\"request-simple\"}")), "write simple request");
TEST_RESULT_VOID(ioWriteFlush(write), "flush simple request");
TEST_RESULT_STR(strPtr(ioReadLine(read)), "{\"out\":true}", "simple request result");
// Assert -- no response will come backup because the process loop will terminate
// Throw an assert error which will include a stack trace
TEST_RESULT_VOID(ioWriteLine(write, strNew("{\"cmd\":\"assert\"}")), "write assert");
TEST_RESULT_VOID(ioWriteFlush(write), "flush simple request");
TEST_RESULT_VOID(ioWriteFlush(write), "flush assert error");
TEST_ASSIGN(result, varKv(jsonToVar(ioReadLine(read))), "parse error result");
TEST_RESULT_INT(varIntForce(kvGet(result, VARSTRDEF("err"))), 25, " check code");
TEST_RESULT_STR(strPtr(varStr(kvGet(result, VARSTRDEF("out")))), "test assert", " check message");
TEST_RESULT_BOOL(kvGet(result, VARSTRDEF("errStack")) != NULL, true, " check stack exists");
// Complex request -- after process loop has been restarted
TEST_RESULT_VOID(ioWriteLine(write, strNew("{\"cmd\":\"request-complex\"}")), "write complex request");
@ -417,8 +429,7 @@ testRun(void)
TEST_RESULT_VOID(protocolServerHandlerAdd(server, testServerProtocol), "add handler");
TEST_ERROR(protocolServerProcess(server), AssertError, "test assert");
TEST_RESULT_VOID(protocolServerProcess(server), "run process loop again");
TEST_RESULT_VOID(protocolServerProcess(server), "run process loop");
TEST_RESULT_VOID(protocolServerFree(server), "free server");
TEST_RESULT_VOID(protocolServerFree(NULL), "free null server");