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

Add server-side logging of non-Thrift exceptions. #186

Open
wants to merge 2 commits into
base: master
Choose a base branch
from

Conversation

markdoliner-doma
Copy link

@markdoliner-doma markdoliner-doma commented Jul 28, 2020

BACKGROUND

Two kinds of exceptions can be thrown by a handler processing a Thrift request:

  • Those that are defined as exceptions in a .thrift file. The server serializes them and sends them to the client. Clients should expect them to happen from time to time and should handle them gracefully.
  • Non-Thrift exceptions: when the server experiences an unhandled error and an exception not defined in a .thrift file is throw out of the handler function. The server has catch-all exception handling that returns a TApplicationException to the client containing the message from the exception.

THIS CHANGE

I modifed the code that generates the server processor to include a console.error() statement that logs exception messages and stack traces when a handler throws a non-Thrift exception. Previously there was no server-side logging for non-Thrift exceptions. The message was sent to the client and the stack trace was discarded entirely. This is not sufficient. Even if you have the exception message received by the client that may not be enough to determine where the error happened. And if you don't control the client then you're REALLY out of luck.

There are no other calls to console.log() or console.error() in the generated code. It could be argued that it's bad form for the generated code to use console.error() since it's sort of like a library, but I think it's more important to log the exception. A better solution might be to allow server implementors to provide a callback function for logging, but I leave that as an exercise for a future developer.

I updated both the Apache code and the thrift-server code, and the tests for both.

Here's the diff of a ping function generated for thrift-server before and after this change:

--- before	2020-07-27 08:05:20.000000000 -0400
+++ after	2020-07-27 08:05:13.000000000 -0400
@@ -1,23 +1,24 @@
     public process_ping(requestId: number, input: thrift.TProtocol, output: thrift.TProtocol, context: Context): Promise<Buffer> {
         return new Promise<string>((resolve, reject): void => {
             try {
                 input.readMessageEnd();
                 resolve(this._handler.ping(context));
             }
             catch (err) {
                 reject(err);
             }
         }).then((data: string): Buffer => {
             const result: IPing__ResultArgs = { success: data };
             output.writeMessageBegin("ping", thrift.MessageType.REPLY, requestId);
             Ping__ResultCodec.encode(result, output);
             output.writeMessageEnd();
             return output.flush();
         }).catch((err: Error): Buffer => {
+            console.error("Unexpected exception while handling ping:", err);
             const result: thrift.TApplicationException = new thrift.TApplicationException(thrift.TApplicationExceptionType.UNKNOWN, err.message);
             output.writeMessageBegin("ping", thrift.MessageType.EXCEPTION, requestId);
             thrift.TApplicationExceptionCodec.encode(result, output);
             output.writeMessageEnd();
             return output.flush();
         });
     }

BACKGROUND

Two kinds of exceptions can be thrown by a handler processing a Thrift request:

- Those that are defined as `exceptions` in a .thrift file. The server serializes them and sends them to the client. Clients should expect them to happen from time to time and should handle them gracefully.
- Non-Thrift exceptions: when the server experiences an unhandled error and an exception not defined in a .thrift file is throw out of the handler function. The server has catch-all exception handling that returns a `TApplicationException` to the client containing the message from the exception.

THIS CHANGE

I modifed the code that generates the server processor to include a console.error() statement that logs exception messages and stack traces when a handler throws a non-Thrift exception. Previously there was no server-side logging for non-Thrift exceptions. The message was sent to the client and the stack trace was discarded entirely. This is not sufficient. Even if you have the exception message received by the client that may not be enough to determine where the error happened. And if you don't control the client then you're REALLY out of luck.

There are no other calls to console.log() or console.error() in the generated code. It could be argued that it's bad form for the generated code to use console.error() since it's sort of like a library, but I think it's more important to log the exception. A better solution might be to allow server implementors to provide a callback function for logging, but I leave that as an exercise for a future developer.

I updated both the Apache code and the thrift-server code, and the tests for both.

Here's the diff of a `ping` function generated for thrift-server before and after this change:
```
--- before	2020-07-27 08:05:20.000000000 -0400
+++ after	2020-07-27 08:05:13.000000000 -0400
@@ -1,23 +1,24 @@
     public process_ping(requestId: number, input: thrift.TProtocol, output: thrift.TProtocol, context: Context): Promise<Buffer> {
         return new Promise<string>((resolve, reject): void => {
             try {
                 input.readMessageEnd();
                 resolve(this._handler.ping(context));
             }
             catch (err) {
                 reject(err);
             }
         }).then((data: string): Buffer => {
             const result: IPing__ResultArgs = { success: data };
             output.writeMessageBegin("ping", thrift.MessageType.REPLY, requestId);
             Ping__ResultCodec.encode(result, output);
             output.writeMessageEnd();
             return output.flush();
         }).catch((err: Error): Buffer => {
+            console.error("Unexpected exception while handling ping: ", err);
             const result: thrift.TApplicationException = new thrift.TApplicationException(thrift.TApplicationExceptionType.UNKNOWN, err.message);
             output.writeMessageBegin("ping", thrift.MessageType.EXCEPTION, requestId);
             thrift.TApplicationExceptionCodec.encode(result, output);
             output.writeMessageEnd();
             return output.flush();
         });
     }
```
This was causing a double space when printed because console.log automatically adds a space between logged items.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

1 participant