Logging File log empty

[luizcarlospedrosogomes]

package.json -> depedencies: ... "@sap-cloud-sdk/util": "^2.11.0",
...

logger.js

const {
    unmuteLogger, createLogger, setGlobalTransports, setGlobalLogLevel,
} = require('@sap-cloud-sdk/util');
const { transports, format } = require('winston');

const consoleFormat = {
    format: format.combine(
        format.splat(),
        format.simple(),
        format.errors({ stack: true }),
    ),
    level: 'info',
    handleExceptions: true,
    json: false,
    colorize: true,
};
setGlobalLogLevel('info');
setGlobalTransports(
    new transports.File({
        name: 'info-file',
        filename: './logs/exceptions.log',
        level: 'info',
        json: false,
    }),
    new transports.Console(consoleFormat),
);
const logger = ({ name }) => createLogger(name);
module.exports = logger;

server.js ` const myLogger = require('./logger')({ name: 'server' }); ...

myLogger.info('ok5');

... `

file log empty

[FrankEssenberger]

Hello @luizcarlospedrosogomes,

I had a quick and compared to our test case for the logger. I experienced the behaviour, that I needed to create the logger before I set the global transport. Could you perhaps change the order in your code so that the createLogger is called before the setGlobalTransports and setGlobalLogLevel.

I guess these methods only effect existing logger. Let me know if this helps.

Best Frank

[luizcarlospedrosogomes]

@FrankEssenberger thanks! logger.js

server.js

test.log

I imagine the problem must be in the call in server.js. But I need to leave this dependency isolated in a file

[FrankEssenberger]

Good morning @luizcarlospedrosogomes,

I think the order is still set before creation. As you wrap the createLogger() in an arrow function the logger is created in line 20 of the server.js whereas the setGlobalTransports is executed by the require which loads the whole file. Can you try in line 9 of the logger.js to write the function like:

const logger = ({name}=>{
   const myLogger = createLogger(name);
   setGlobalTransports(fileTransport);
   return myLogger
}

Best Frank

[luizcarlospedrosogomes]

Good morning @FrankEssenberger

Sorry for the delay, I followed your suggestion but I got another error

` const fileTransport = new transports.File({ filename: 'test.log', level: 'info', });

const logger = ({ name }) => { const myLogger = createLogger(name); setGlobalTransports(fileTransport); return myLogger; };

module.exports = logger; `

error `

[email protected] start cds run

[cds] - loading server from { file: 'srv/server.js' } (node:796) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 error listeners added to [File]. Use emitter.setMaxListeners() to increase limit (Use node --trace-warnings ... to show where the warning was created) (node:796) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 unpipe listeners added to [File]. Use emitter.setMaxListeners() to increase limit (node:796) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 drain listeners added to [File]. Use emitter.setMaxListeners() to increase limit (node:796) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 close listeners added to [File]. Use emitter.setMaxListeners() to increase limit (node:796) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 finish listeners added to [File]. Use emitter.setMaxListeners() to increase limit [ERROR] write after end at writeAfterEnd (/workspace/node_modules/readable-stream/lib/_stream_writable.js:261:12) at PassThrough.Writable.write (/workspace/node_modules/readable-stream/lib/_stream_writable.js:305:21) at File.log (/workspace/node_modules/winston/lib/winston/transports/file.js:185:34) at File._write (/workspace/node_modules/winston-transport/index.js:82:19) at doWrite (/workspace/node_modules/readable-stream/lib/_stream_writable.js:409:139) at writeOrBuffer (/workspace/node_modules/readable-stream/lib/_stream_writable.js:398:5) at File.Writable.write (/workspace/node_modules/readable-stream/lib/_stream_writable.js:307:11) at DerivedLogger.ondata (/workspace/node_modules/readable-stream/lib/_stream_readable.js:681:20) at DerivedLogger.emit (node:events:513:28) at addChunk (/workspace/node_modules/readable-stream/lib/_stream_readable.js:298:12) ` I haven't had time to investigate the error yet but I thought it was important to give you some feedback

[FrankEssenberger]

Good morning,

at least the stream seems to be considered now :-). I found an issue which seems to be also the problem here. Something with passing things as reference not value in the add()function we also use. I do not really get why it is not showing in our test. I simply get the file there. I even removed the log.

I think it would be good to simplify the situation and put the logger creation all in the same file to see where the passing around causes a problem. So first put logger creation in the server.js (just as a test). When this works step by step move the code to a function like you have and see when it breaks.

Best Frank

[luizcarlospedrosogomes]

server.js ` const { transports } = require('winston'); const { createLogger, setGlobalTransports } = require('@sap-cloud-sdk/util');

... const fileTransport = new transports.File({ filename: 'test.log', level: 'info', });

setGlobalTransports(fileTransport); const myLogger = createLogger('server'); ... ` log on start

[cds] - loading server from { file: 'srv/server.js' } [2022-12-08T13:56:24.495Z] INFO (server): CDS API Boostrap from /srv/server.js (node:2744) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 unpipe listeners added to [File]. Use emitter.setMaxListeners() to increase limit (Usenode --trace-warnings ...` to show where the warning was created) (node:2744) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 error listeners added to [File]. Use emitter.setMaxListeners() to increase limit (node:2744) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 drain listeners added to [File]. Use emitter.setMaxListeners() to increase limit (node:2744) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 close listeners added to [File]. Use emitter.setMaxListeners() to increase limit (node:2744) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 finish listeners added to [File]. Use emitter.setMaxListeners() to increase limit [cov2ap] - [HPM] Proxy created: / -> http://localhost:4004 [cov2ap] - [HPM] Proxy rewrite rule created: "^/v2" ~> "" [cov2ap] - [HPM] Proxy created: / -> http://localhost:4004 [cov2ap] - [HPM] Proxy rewrite rule created: "^/v2" ~> "" [cds] - loaded model from 6 file(s):

db/schema.cds srv/index.cds db/data/model.cds srv/src/models/solicitation-service.cds db/data/views.cds db/data/views_expand.cds ` test.log [90m[2022-12-08T13:56:14.701Z][39m [32mINFO[39m [34m(server)[39m: CDS API Boostrap from /srv/server.js

That way, despite the log indicating the need for some intention, it worked, but now how to make it work in isolation?

[luizcarlospedrosogomes]

https://github.com/winstonjs/winston/issues/1573#issuecomment-880833813

I followed this comment fully, implemented the code that is as an example. It worked I have the log files too. But the sap package, this package, was left out.

[FrankEssenberger]

hm, I do not know. This is issue is strange and I can not reproduce it. I think there must be some problem with calling things by reference creating shallow copies if you adjust a logger after creation. This is what we do when calling setGlobalTransports. In the example the logger is created correctly right away. Perhaps you can try putting everything inside the function scope:

export const loggerBuilder = (name: string): Logger => {
  const myLogger = createLogger(name);
  const fileTransport = new transports.File({
    filename: 'test.log',
    level: 'info'
  });
  setGlobalTransports(fileTransport);
  return myLogger;
};

If this also does not help I, I would perhaps use the code sample you found. @marikaner do you have an idea on this issue?

Best Frank

[marikaner]

@luizcarlospedrosogomes, it has been a long time since this issue was discussed. Were you able to solve or work around it since then?

[luizcarlospedrosogomes]

@luizcarlospedrosogomes, it has been a long time since this issue was discussed. Were you able to solve or work around it since then?

It was implemented as per the guidance, I didn't return to the scenario again.

I must return soon

[jjtang1985]

I will close this issue, as we did not get an update. Please reopen it, if needed.