cds-dbs icon indicating copy to clipboard operation
cds-dbs copied to clipboard

[WIP] fix(log): respect `sqlite` and `hana` logger IDs

Open schwma opened this issue 1 year ago • 6 comments

Hi @danjoa,

Could you please take a look at the following issue?

In @cap-js/cds-dbs logging of SQL statements is handled by the base class SQLService which presently instantiates a cds logger using the module string sql|db. This means logging cannot be enabled for the module names sqlite (and hana) as was the case previously and as is documented in capire.

In the old DB layer, the logger responsible for logging SQLite statements was instantiated using the module string sqlite|db|sql and the SAP HANA logger was instantiated using the module string hana|db|sql. This allowed logging to be enabled using DEBUG=sqlite and DEBUG=hana respectively, as well as:

{
  "cds": {
    "log": {
      "levels": {
        "sqlite": "debug",
        "hana": "debug"
      }
    }
  }
}

The problem lies in restoring this functionality in the new DB layer, due to the architecture of the new DB layer and the way the cds.log API currently works (with regards to picking the first module name in the module string as a logger id and caching the logger instance).

If logging should continue to be handled by the base class SQLService, the logger needs to be instantiated with the module string that contains the name of the currently used DB module. This could be done explicitly by passing all module names to the logger, e.g. sqlite|hana|sql|db, but this would require knowledge about the child classes in the base class. Additionally this logger would only be able to be configured using the module string sqlite (first module as logger id) since the remaining modules are only respected by the env var DEBUG, but by the cds.env.log configuration. Alternatively something like this could be done cds.log(`${cds.requires.db.kind}|db|sql`), but this doesn't seem ideal either.

Alternatively logging could be implemented by the child classes themselves, but this would introduce duplicate code that could be avoided in the base class.

Additionally, please note that SQLService instantiates a logger using the module string sql|db (see here) and CQN2SQLRenderer instantiates a logger using the module string sql|sqlite (see here). This means that both loggers have the same logger id sql, which means that the module sqlite is always ignored if SQLService is instantiated before CQN2SQLRenderer and caches the logger. This means that instantiating loggers with the same logger id is fragile unless the logger is always instantiated with the exact same module string listing all modules.

Do you have any ideas on how to best solve this issue?

Best regards, Marcel

schwma avatar Apr 10 '24 14:04 schwma

Since only one db kind is active at a time, there's no business value in fine-granular control between hana and sqlite, hence my proposal:

  • Adapt the documentation and remove the possibility to log for hana or sqlite. The only values should be db and sql.

  • Adapt the mentioned loggers to use db|sql.

We might also change the behaviour so that db logs everything on the db layer whereas sql only logs sql statements, but I would postpone that decision.

If there should be a strong demand to enable db logging with hana/sqlite (backwards compatibility), we can implicitly change it to db, but I wouldn't do that until there are real stakeholder complaints (so far, there aren't?).

David-Kunz avatar Aug 07 '24 07:08 David-Kunz

Since only one db kind is active at a time, there's no business value in fine-granular control between hana and sqlite, hence my proposal:

  • Adapt the documentation and remove the possibility to log for hana or sqlite. The only values should be db and sql.
  • Adapt the mentioned loggers to use db|sql.

We might also change the behaviour so that db logs everything on the db layer whereas sql only logs sql statements, but I would postpone that decision.

If there should be a strong demand to enable db logging with hana/sqlite (backwards compatibility), we can implicitly change it to db, but I wouldn't do that until there are real stakeholder complaints (so far, there aren't?).

can't the respective db service propagate the setting? e.g., something like:

class HANAService extends SQLService {
  constructor(...args) {
    if (cds.env.log.levels.hana >= cds.env.log.levels.db) cds.env.log.levels.db = cds.env.log.levels.hana
    super([...args])
  }

but there is also this: https://github.com/cap-js/cds-dbs/blob/ac58f9af052e16c7483112569e536b8b8dd0e1da/hana/lib/HANAService.js#L16C19-L16C24

sjvans avatar Aug 07 '24 08:08 sjvans

Since only one db kind is active at a time, there's no business value in fine-granular control between hana and sqlite, hence my proposal:

  • Adapt the documentation and remove the possibility to log for hana or sqlite. The only values should be db and sql.
  • Adapt the mentioned loggers to use db|sql.

We might also change the behaviour so that db logs everything on the db layer whereas sql only logs sql statements, but I would postpone that decision. If there should be a strong demand to enable db logging with hana/sqlite (backwards compatibility), we can implicitly change it to db, but I wouldn't do that until there are real stakeholder complaints (so far, there aren't?).

can't the respective db service propagate the setting? e.g., something like:

class HANAService extends SQLService {
  constructor(...args) {
    if (cds.env.log.levels.hana >= cds.env.log.levels.db) cds.env.log.levels.db = cds.env.log.levels.hana
    super([...args])
  }

but there is also this: https://github.com/cap-js/cds-dbs/blob/ac58f9af052e16c7483112569e536b8b8dd0e1da/hana/lib/HANAService.js#L16C19-L16C24

Either that, or we can do

class HANAService extends SQLService {
   constructor(...args) {
     this.LOG = cds.log('db|hana|sql')
  }
}

and base classes could call this.LOG.

That being said, I still wouldn't do that. Currently, DEBUG=hana doesn't work and as long as nobody complains, why should we enable it?

David-Kunz avatar Aug 07 '24 09:08 David-Kunz

That being said, I still wouldn't do that. Currently, DEBUG=hana doesn't work and as long as nobody complains, why should we enable it?

also with legacy dbs and 'sqlite'? i.e., the docs were always incorrect?

sjvans avatar Aug 07 '24 09:08 sjvans

No, with legacy sqlite, it was possible.

David-Kunz avatar Aug 07 '24 09:08 David-Kunz

No, with legacy sqlite, it was possible.

then i'd restore. but let's wait for @johannes-vogel

sjvans avatar Aug 07 '24 13:08 sjvans

I'd also just keep it as it is → we always log under sql, which makes it easier as compared to the past. Note that the alternative ids specified after | are only for matching with DEBUG env variables, not for configuring loggers. (→ see https://pages.github.tools.sap/cap/docs/node.js/cds-log#matching-multiple-values-of-debug)

danjoa avatar Aug 20 '24 11:08 danjoa

As discussed, keep it as it is

schwma avatar Aug 28 '24 11:08 schwma