dapr / js-sdk

Dapr SDK for Javascript
Apache License 2.0
197 stars 82 forks source link

"TypeError: Converting circular structure to JSON" while using custom winston logger service #488

Closed HCarnegie closed 4 months ago

HCarnegie commented 1 year ago

Expected Behavior

Using a custom winston logger service for the DaprServer object, should not cause an error.

Actual Behavior

Following the instruction of the sdk docs to use a custom winston logger service for the DaprServer object, it's going to raise an exception as soon as the DaprServer object is instantiated.

== APP == TypeError: Converting circular structure to JSON
== APP ==     --> starting at object with constructor 'DerivedLogger'
== APP ==     |     property '_readableState' -> object with constructor 'ReadableState'
== APP ==     |     property 'pipes' -> object with constructor 'Array'
== APP ==     |     index 0 -> object with constructor 'File'
== APP ==     --- property 'parent' closes the circle
== APP ==     at JSON.stringify (<anonymous>)
== APP ==     at new HTTPServer (./dapr/js-sdk/examples/http/actor-parking-sensor/node_modules/@dapr/dapr/implementation/Server/HTTPServer/HTTPServer.js:41:66)
== APP ==     at new DaprServer (./dapr/js-sdk/examples/http/actor-parking-sensor/node_modules/@dapr/dapr/implementation/Server/DaprServer.js:80:32)
== APP ==     at start (./dapr/js-sdk/examples/http/actor-parking-sensor/dist/index.js:36:20)
== APP ==     at Object.<anonymous> (./dapr/js-sdk/examples/http/actor-parking-sensor/dist/index.js:91:1)
== APP ==     at Module._compile (node:internal/modules/cjs/loader:1254:14)
== APP ==     at Module._extensions..js (node:internal/modules/cjs/loader:1308:10)
== APP ==     at Module.load (node:internal/modules/cjs/loader:1117:32)
== APP ==     at Module._load (node:internal/modules/cjs/loader:958:12)
== APP ==     at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:81:12)

Steps to Reproduce the Problem

using package "@dapr/dapr": "^3.0.0"

I can reproduce the exception by adopting following steps to the actor-parking-sensor example:

  1. Create Winston Logger Service:
    
    import { LoggerService } from "@dapr/dapr";
    import * as winston from "winston";

export class WinstonLoggerService implements LoggerService { private logger;

constructor() { this.logger = winston.createLogger({ level: 'info', format: winston.format.json(), defaultMeta: { service: 'user-service' }, transports: [ // // - Write all logs with importance level of error or less to error.log // - Write all logs with importance level of info or less to combined.log // new winston.transports.File({ filename: 'error.log', level: 'error' }), new winston.transports.File({ filename: 'combined.log' }), ], }); }

error(message: any, ...optionalParams: any[]): void { this.logger.error(message, ...optionalParams); } warn(message: any, ...optionalParams: any[]): void { this.logger.warn(message, ...optionalParams); } info(message: any, ...optionalParams: any[]): void { this.logger.info(message, ...optionalParams); } verbose(message: any, ...optionalParams: any[]): void { this.logger.verbose(message, ...optionalParams); } debug(message: any, ...optionalParams: any[]): void { this.logger.debug(message, ...optionalParams); } }

2. import logger on [index.ts](https://github.com/dapr/js-sdk/blob/v3.0.0/examples/http/actor-parking-sensor/src/index.ts)
``` Typescript
import { WinstonLoggerService } from "./logger";
  1. pass logger instance via options to DaprServer constructor inside the start function:

passing the logger to the clientOptions or to serverOptions --> fails:

...
 const winstonLoggerService = new WinstonLoggerService();
  const logger = {
    level: LogLevel.Debug,
    service: winstonLoggerService,
  };

  const clientOptions = {
    daprHost,
    daprPort,
   // logger, // this fails
  };

  const server = new DaprServer({
    serverHost,
    serverPort,
    clientOptions,
   // logger, // this fails
  });
  const client = new DaprClient(clientOptions); 
...

passing the logger only to the client constructor --> works fine:

...
 const winstonLoggerService = new WinstonLoggerService();
  const logger = {
    level: LogLevel.Debug,
    service: winstonLoggerService,
  };

  const clientOptions = {
    daprHost,
    daprPort,
   // logger, // this fails
  };

  const server = new DaprServer({
    serverHost,
    serverPort,
    clientOptions,
   // logger, // this fails
  });
  const client = new DaprClient({ ...clientOptions, logger }); // this works
...

The winston logger is a circular structured object and the HTTPServer constructor serializes the options on the constructor: this.logger.debug(Configured HTTPServer Options: ${JSON.stringify(options)});

The same behavior can be reproduced when such an object is passed to any actor method. cause the arguments are serialized as well.

HCarnegie commented 1 year ago

Possible solutions would be:

  1. using a replacer passed to the JSON.stringify() function:

    const getCircularReplacer = () => {
    const seen = new WeakSet();
    return (key: any, value: object | null) => {
    if (typeof value === "object" && value !== null) {
      if (seen.has(value)) {
        return;
      }
      seen.add(value);
    }
    return value;
    };
    };
    ... 
    this.logger.debug(`Configured HTTPServer Options: ${JSON.stringify(options, getCircularReplacer())}`);
    ...
  2. Use the flatted package to resolve circular references:

    
    import { stringify } from 'flatted';
    ...
    this.logger.debug(`Configured HTTPServer Options: ${stringify(options)}`);
    ...
shubham1172 commented 1 year ago

Nice find, @HCarnegie! Another option could be to skip stringify-ing options.logger.service altogether? Maybe something like this -

JSON.stringify( that.person, function( key, value) {
  if( key == 'logger') { return logger.level; }
  else {return value;}
})

https://stackoverflow.com/a/12659424/4654175

HCarnegie commented 1 year ago

Yes this could be a solution to avoid the error on logging the options, with the nice side effect not printing out the whole logger object.

But we are facing the same issue at logging actor method calls, if a circular object is passed as an argument to the actor method. Even if no custom winston logger is configured for the DaprServer Object:

As an example I passed a circular object to dapr actor method.

The actor interface:

interface IDemoCircularOpject {
  circ?: IDemoCircularOpject;
}

interface IDemoActor {
  test(circ: IDemoCircularOpject): void;
}

The actor method call:

...
this.actorBuilder = new ActorProxyBuilder<IDemoActor>(
      DemoActor,
      dapr.client
    );

const actor = this.actorBuilder.build(ActorId.createRandomId());
const circObj: IDemoCircularOpject = {};
circObj.circ = circObj;

actor.test(circObj);

It will raises the following error - (similar to the one in my first comment - but occurs on another code path ): ./dapr/utils/Serializer.util.js:56

== APP == ./dapr/utils/Serializer.util.js:56
== APP ==             serializedData = JSON.stringify(data);
== APP ==                                   ^
== APP == TypeError: Converting circular structure to JSON
== APP ==     --> starting at object with constructor 'Object'
== APP ==     --- property 'circ' closes the circle
== APP ==     at JSON.stringify (<anonymous>)
== APP ==     at Object.serializeHttp (./dapr/utils/Serializer.util.js:56:35)
== APP ==     at HTTPClient.<anonymous> ./dapr/implementation/Client/HTTPClient/HTTPClient.js:144:72)
== APP ==     at Generator.next (<anonymous>)
== APP ==     at ./dapr/implementation/Client/HTTPClient/HTTPClient.js:39:71
== APP ==     at new Promise (<anonymous>)
== APP ==     at __awaiter (./dapr/implementation/Client/HTTPClient/HTTPClient.js:35:12)
== APP ==     at HTTPClient.execute (./dapr/implementation/Client/HTTPClient/HTTPClient.js:130:16)
== APP ==     at ActorClientHTTP.<anonymous> (./dapr/actors/client/ActorClient/ActorClientHTTP.js:31:46)
== APP ==     at Generator.next (<anonymous>)
shubham1172 commented 1 year ago

The problem is that JSON does not accept circular references. This data gets serialized to be transported over the HTTP request. If it's indeed circular, it should throw an error IMO because there is no actual representation of this over JSON.

If we try to handle this on our end and say use something like getCircularReplacer, it won't be the same data once it goes through serialize and deserialize, thus resulting in "data loss". I'd propose to let these scenarios error out.

HCarnegie commented 1 year ago

That makes sense. Thanks for pointing this out.

Is there a way that actor objects could have methods which are not exposed to HTTP Server? Just methods only accessible for local code? E.g. to inject complex objects or functions?

XavierGeerinck commented 1 year ago

My two cents:

  1. We should indeed fix the stringification of the logger and skip the circular import stringify
  2. Won't fix as this is nate to JSON and Javascript, circular references are not supported and are the responsibility of the developer

For your last question, could you make a separate issue for this please? "Allow private methods on actors that cannot be invoked" -> e.g., if _ is present in the method name at the start, we could maybe threat it as a local functions

If you are open to give it a shot, it would be in this method: https://github.com/dapr/js-sdk/blob/main/src/actors/runtime/ActorManager.ts#L132 which is responsible for checking if the method exists or not. Theoretically it could be a simple as adding a check that states "if string starts with _, throw error that it's a private function and don't invoke it"

sohocine commented 4 months ago

As of v3.3.1, this bug is still occurring and simply preventing the use of a CustomLogger in a DaprServer. Since the service property takes in a class instance, this will always throw an error. I suggest that only the instance name should be logged by this.logger.debug(`Configured HTTPServer Options: ${JSON.stringify(options)}`);, and not the instance itself.