Logging fixes (#475)

- Use vm logger for invocation start/end logs
- The vm logger should have source: journal
- We should use the custom logger for logs that happen before the start
  message is processed
- We should use the terminology 'Invocation completed' not 'Function
  completed'
- Bring back 'Replaying invocation'

packages/restate-sdk/src/context_impl.ts

@@ -84,6 +84,7 @@ export class ContextImpl implements ObjectContext, WorkflowContext {
     readonly input: vm.WasmInput,
     public readonly console: Console,
     public readonly handlerKind: HandlerKind,
+    private readonly vmLogger: Console,
     private readonly invocationRequest: Request,
     private readonly invocationEndPromise: CompletablePromise<void>,
     private readonly inputReader: ReadableStreamDefaultReader<Uint8Array>,
@@ -835,7 +836,7 @@ export class ContextImpl implements ObjectContext, WorkflowContext {
       !(error instanceof RestateError) ||
       error.code !== SUSPENDED_ERROR_CODE
     ) {
-      this.console.warn("Function completed with an error.\n", error);
+      this.vmLogger.warn("Invocation completed with an error.\n", error);
     }
     this.coreVm.notify_error(error.message, error.stack);
 

packages/restate-sdk/src/endpoint/handlers/generic.ts

@@ -237,6 +237,19 @@ export class GenericHandler implements RestateHandler {
       }
     );
 
+    // Use a default logger that still respects the endpoint custom logger
+    // We will override this later with a logger that has a LoggerContext
+    // See vm_log below for more details
+    invocationLoggers.set(
+      loggerId,
+      createLogger(
+        this.endpoint.loggerTransport,
+        LogSource.JOURNAL,
+        undefined,
+        () => false
+      )
+    );
+
     const inputReader = body.getReader();
 
     // Now buffer input entries
@@ -290,14 +303,18 @@ export class GenericHandler implements RestateHandler {
     );
     const vmLogger = createLogger(
       this.endpoint.loggerTransport,
-      LogSource.USER,
+      LogSource.JOURNAL,
       loggerContext,
       // Filtering is done within the shared core
       () => false
     );
     // See vm_log below for more details
     invocationLoggers.set(loggerId, vmLogger);
-    ctxLogger.info("Starting invocation.");
+    if (!coreVm.is_processing()) {
+      vmLogger.info("Replaying invocation.");
+    } else {
+      vmLogger.info("Starting invocation.");
+    }
 
     // This promise is used to signal the end of the computation,
     // which can be either the user returns a value,
@@ -316,6 +333,7 @@ export class GenericHandler implements RestateHandler {
       input,
       ctxLogger,
       handler.kind(),
+      vmLogger,
       invocationRequest,
       invocationEndPromise,
       inputReader,
@@ -328,15 +346,15 @@ export class GenericHandler implements RestateHandler {
       .then((bytes) => {
         coreVm.sys_write_output_success(bytes);
         coreVm.sys_end();
-        ctxLogger.info("Invocation completed successfully.");
+        vmLogger.info("Invocation completed successfully.");
       })
       .catch((e) => {
         const error = ensureError(e);
         if (
           !(error instanceof RestateError) ||
           error.code !== SUSPENDED_ERROR_CODE
         ) {
-          ctxLogger.warn("Invocation completed with an error.\n", error);
+          vmLogger.warn("Invocation completed with an error.\n", error);
         }
 
         if (error instanceof TerminalError) {