When passing an object that contains fields as arrays or even an array as a custom field we get a mutation from array type to string type (in case of object fields) or array elements are converted to strings This happens from versions > 1.1.2

Code used for testing

const logger= require('cf-nodejs-logging-support');
const a = [ { x: [1,2], y: 2, z: false, t: {}}];
logger.logMessage('info', 'Test', a);
console.log(typeof a[0], typeof a[0].x, typeof a[0].y, typeof a[0].z, typeof a[0].t);

Version 1.1.2 output
{"written_at":"2018-05-09T10:02:09.876Z","written_ts":446547752869439,"component_type":"application","component_id":"-","component_name":"-","component_instance":"0","layer":"[NODEJS]","space_name":"-","space_id":"-","source_instance":"0","container_id":"-","logger":"nodejs-logger","msg":"Test:","type":"log","custom_fields":[{"x":[1,2],"y":2,"z":false,"t":{}}],"level":"info"}
object object number boolean object

Version 3.0.4 output
{"component_type":"application","component_id":"-","component_name":"-","component_instance":"0","layer":"[NODEJS]","organisation_id":"-","organisation_name":"-","space_name":"-","space_id":"-","container_id":"-","logger":"nodejs-logger","source_instance":"0","written_at":"2018-05-09T10:11:19.763Z","written_ts":447097639918326,"msg":"Test:","type":"log","custom_fields":["{\"x\":[1,2],\"y\":2,\"z\":false,\"t\":{}}"],"level":"info"}
string undefined undefined undefined undefined

A logging level 'OFF' should be added to allow disabling of logging output. This will be useful for unit tests.

Hey everyone,

when working with this library together with the xs-security library from SAP, I encounter the following problem:

I have two routers: One for unauthenticated calls to my app, one for authenticated (JWT) ones. As per my understanding, when the request arrives at the app, the logNetwork function gets executed and due to this, also the tenant_id is set. If there is no tenant id in the header field present, "-" will be set as default. This behavior is fine for the unauthenticated routes.
But for the authenticated ones, I would like to be able to add the tenant id, after the call passed the passport strategy (and the subaccount id was extracted from the token), so that I have reference to the right tenant.

I have a, in my eyes, rather hacky solution, which is putting another middleware before the logNetwork call, where the authorization header is checked, and if a JWT is present, the tenant id will be extracted. But doing it this way, we have basically two places where I need to check for the authorization header.
I know that there are custom fields, but I would like to set the root field, to not have multiple possible fields afterwards.

I would like to see some function like the setCorrelationId, also for the tenant (maybe for all root fields?). Is there already a way to achieve this?
Let me know your thoughts 😀

BR Robert

My understanding for correlation_id (having in mind the description) is that it is a value which is the same for all requests to different applications that take part in the processing of a single logical transaction. And if there isn't such a logical transaction, then I would not expect a value for this field. But in the config I see that if the request header x-corelationid is not present, then the value of request_id will be taken. Why?

Here are the reasons why I think this is a bit confusing:

• Lets have a standalone request. The logs will state that the current request is part of a logical transaction (there is a value for the field) when actually it isn't. Of course, one may say that it is a transaction consisting of a single request, but does the correlation_id bring benefit in that case? We already have the request_id.
• There are 2 properties with the same value: correlation_id and request_id and this is just not necessary.

Now there is always a value for correlation_id, but not always for request_id (from the config, if the x-vcap-request-id header is not present). But to me it seems more logical to always have a request_id (since we are logging during the processing of a request) and to not always have a correlation_id (since not always the request will be a part of a logical transaction involving multiple requests).

Regarding filtering: one can use request_id, and only if he/she knows the correlation id to filter by correlation_id.

Many thanks and best regards
Petar

package.json says version 1.1.1, whereas npm has version 1.1.2. Where can I find a direct download for 1.1.2?

I am not able to see logs in Chrome Devtools & other Node Js debuggers.

On inspection I found that cf-nodejs-logging-support is using process.stdout.write instead of console.log/error/warn/.....

process.stdout.write output isn't sent over v8-inspector debug protocol socket. Thus, logs are not visible in any debugger.

winstonjs/winston#981
microsoft/vscode#19750

1. How can we use debuggers with cf-nodejs-logging-support?
2. If not, Is there any alternative which can be used?

Hi can we get typings for `

• error
• warn
• info
• verbose
• debug
• silly

That would be great, thanks!

I would like to log some context information for every log. Currently, I am only interested in the custom logs. I can add this information to the custom fields like this:

const logger = require('cf-nodejs-logging-support');
logger.info('Information log.', { CONTEXT: 'context'});

but I don't want to add the context manually to every log statement. What I would like to do instead would be something like this:

const { createLogger } = require('cf-nodejs-logging-support');
const logger = createLogger({ CONTEXT: 'context'});
logger.info('Information log.');

I would like to create an instance of a logger, that has its own context. This currently does not seem to be possible with this library. I tried to add a wrapper for this, but I don't see a clean way to achieve this. Am I overseeing something?

Hi,

Our team develop a new service in Cloud Foundry, the service include 3 Node Js micro-services.
we want to follow after new request between the micro-services, the problem is that the logger change the correlation-id / request-id when we send new request between the micro-services.
there is a way to keep the same correlation-id/request-id for all the forwarding requests ?

Thanks,
Nir Shchori

Hi Colleagues,
One of the fields in the pattern is the {{organization_name}}, and this field is not working although it is written in https://github.com/SAP/cf-java-logging-support/blob/master/cf-java-logging-support-core/beats/request-metrics/docs/fields.asciidoc
Is this a bug or by design?
Regards,
Assaf

Hello,

in the README it should say redacted and not reducted. https://www.npmjs.com/package/cf-nodejs-logging-support/v/3.0.1#sensitive-data-reduction

Kind regards,

a user

Hey, what is the best practice to set the correlationId (or logContext) when the message is not received from a HTTP Request, but from a message Queue like RabbitMQ?

Also how to make sure that asynchronous (and therefore 'parallel') consumption occuring in one instance of the microservice can still distinguish different correlationIds?

Hello,

i've got an issue when defining a log pattern.

For example:
I define the log pattern:

log.setLogPattern("{{written_at}} - [{{level}}] {{correlation_id}} {{msg}} {{request}}");

A normal

log.logMessage("info", "I am listening on port 1337"); 

would result in an output like:

2017-12-08T10:28:08.653Z - [info] {{correlation_id}} I am listening on port 1337 {{request}}

A express log output would look like:

2017-12-08T10:28:12.323Z - [info] 985fd5cd-eab1-40ea-8221-2725f585ecf4 {{msg}} /red/

The problem is, the "writeLogToConsole" function just replaces the placeholder with keys which are in the logObject.

A solution cloud be:
https://github.com/SAP/cf-nodejs-logging-support/blob/master/cf-nodejs-logging-support-core/log-core.js

Add

output = output.replace(/{{.*?}}\s?/g, '');`

after the for loop.

Like:

	var output = pattern;
	for (var key in options.meta) {
		if (typeof (options.meta[key]) === "object" && validObject(options.meta[key])) {
			output = output.replace('{{' + key + '}}', JSON.stringify(options.meta[key]));
		} else {
			output = output.replace('{{' + key + '}}', options.meta[key]);
		}
	}
	output = output.replace(/{{.*?}}\s?/g, '');
	return output;

In the past we have used log.createCorrelationObject() to create a child logger that logs a correlation id even though it didn't come from an incoming HTTP request. Is it possible to do that in v6.0.0, as it seems like you have removed the function?

I was wondering if we might get in the future any integration with pino logging framework (https://github.com/pinojs/pino) as an alternative to winston.

Provide api functions to check whether a given logging level is active in current context. E.g. isDebug(), isVerbose(), isInfo()...

to match functionality of the java library and to enable future use cases, some data from VCAP_APPLICATION shall be written in the logs as well.In particular:

• "application_id";
• "application_name";
• "instance_index";
• "space_id";
• "space_name";
• "organization_id";
• "organization_name

Java implementation as reference:
https://github.com/SAP/cf-java-logging-support/blob/8d835d382bf08614226b823d835cd21a6952e992/cf-java-logging-support-core/src/main/java/com/sap/hcp/cf/logging/common/VcapEnvReader.java#L32

Hi all,

we are using winston for logging in our backend application on SAP Cloud Platform - Cloud Foundry in the following Versions:

...
"cf-nodejs-logging-support": "5.2.5",
"winston": "3.2.1"
...

Based on your example for winston custom messages I have the following minimal example:

const log = require('cf-nodejs-logging-support');
const winston = require('winston');
const someTransport = log.createWinstonTransport();
const logger = winston.createLogger({
    // Bind transport to winston
    transports: [
      someTransport,
      new winston.transports.Console({
        format: winston.format.simple()
      }),
    ],
});
const intId = setInterval(() => {
  logger.warn('log me please');
}, 3000);

However the problem is, that the "cf-nodejs-logging-support"-transport will only log the very first message. After that no more messages are logged. To validate that this issue is not a general issue of winston I have added the standard console transport. The console transport works as expected and logs all messages. Output from the console:

{"component_type":"application","component_id":"-","component_name":"-","component_instance":"0","layer":"[NODEJS]","organization_id":"-","organization_name":"-","space_name":"-","space_id":"-","container_id":"-","logger":"nodejs-logger","source_instance":"0","written_at":"2019-09-12T08:29:04.569Z","written_ts":69149234026024,"level":"warn","msg":"log me please","type":"log"}
warn: log me please
warn: log me please
warn: log me please
warn: log me please

As you can see after the first messages only the warn: log me please are printed whereas the JSON-logs from this library here are missing.
Somehow the logMessage-method of the transport (winston-transport.js#L12) is only called once.

I discovered, that the timestamp "written_ts" is off by a lot, due to beeing not correlated with world time.
One timestamp I got was: 5236162006546 which translates to 12/5/2135, 6:26:46 PM.

The cf-java-logging-support module has separation between capturing logs and printing them to the console, allowing the user (i.e. the developer) to determine the output format (e.g. JSON vs. plain text).

Especially for development and local testing, plain text logs are much easier to read then their JSON representation.

Is there any chance you can add functionality to specify the output format?

Thanks,
Max

Hi ,

i found out that when try to log my requests with a pattern like
setLogPattern('[{{level}}] {{written_at}} - {{msg}}')
it works fine for all normal logs when i use it in the application.
However when i use it with express like

service.use(log.logNetwork);

The message will be always empty which leads to logs like :
[info] 2017-12-06T13:54:16.718Z - [{{msg}}]

Better would be if we either would write nothing instead of {{msg}} or we could make a condition to use one format for express logging and one format for normal logs.

Is this possible or is this a bug?

Hi,

when i try to use the library to log complex things in my application log i would love to keep the correlation id. Means one request from express comes in and in the following req/response cycle in want to use the same correlation id for all my logs.

So far i did not see how i can pass the correlation id when i use logger() function.
Thanks
Alex

Is there a public API to read the correlation_id, e.g. to pass it to another service (service-to-service communication)?

When logging the lib, there are information like e. g. component_name that are already represented in the logs as cf_app_name. Why does this duplication exist and is it documented anywhere?

Hello ,

in our application we will during a trace also write certain numeric statistic like memory usage etc..
All these additional fields are written as custom fields. When we check on the custom field in Kibana the fields are there just as string fields and not as numeric.

Is there a way how to format custom fields as numeric?

Hi, probably a node.js newby question:
I would like to use your lib without any express nor winston library.
Could you please also information on how to do that?
Thanks, Wolfgang

Dear experts
I am trying to build extend my jabber app adding module "botkit-middleware-dialogflow": "^2.0.4" , but it returns the below error could you please help find the cause of the issue

Thanks

4:04:35 PM (Builder) Build of "/CiscoJabber/myjabber" started.
4:04:44 PM (DIBuild) Build of "/CiscoJabber/myjabber" in progress.
4:04:45 PM (DIBuild) Service provisioning for module: '/myjabber'[INFO] Injecting source code into builder...[INFO] Source code injection finished[INFO] ------------------------------------------------------------------------
4:05:13 PM (DIBuild) > [email protected] install /home/vcap/app/.java-buildpack/tomcat/temp/builder/sap.nodejs/builds/build-6798269379419657313/myjabber/node_modules/grpc> node-pre-gyp install --fallback-to-build --library=static_librarygyp ERR! configure error gyp ERR! stack Error: ENOENT: no such file or directory, open '/home/vcap/app/META-INF/resources/nodejs/aggr.pem'gyp ERR! stack at Object.fs.openSync (fs.js:646:18)gyp ERR! stack at Object.fs.readFileSync (fs.js:551:33)gyp ERR! stack at readCAFile (/home/vcap/app/.java-buildpack/tomcat/temp/nodejsbin5846029318158714442/node-v8.9.1-linux-x64/lib/node_modules/npm/node_modules/node-gyp/lib/install.js:466:15)gyp ERR! stack at download (/home/vcap/app/.java-buildpack/tomcat/temp/nodejsbin5846029318158714442/node-v8.9.1-linux-x64/lib/node_modules/npm/node_modules/node-gyp/lib/install.js:438:22)gyp ERR! stack at /home/vcap/app/.java-buildpack/tomcat/temp/nodejsbin5846029318158714442/node-v8.9.1-linux-x64/lib/node_modules/npm/node_modules/node-gyp/lib/install.js:185:19gyp ERR! stack at /home/vcap/app/.java-buildpack/tomcat/temp/nodejsbin5846029318158714442/node-v8.9.1-linux-x64/lib/node_modules/npm/node_modules/mkdirp/index.js:48:26gyp ERR! stack at FSReqWrap.oncomplete (fs.js:153:5)gyp ERR! System Linux 4.15.0-39-genericgyp ERR! command "/home/vcap/app/.java-buildpack/tomcat/temp/nodejsbin5846029318158714442/node-v8.9.1-linux-x64/bin/node" "/home/vcap/app/.java-buildpack/tomcat/temp/nodejsbin5846029318158714442/node-v8.9.1-linux-x64/lib/node_modules/npm/node_modules/node-gyp/bin/node-gyp.js" "configure" "--fallback-to-build" "--library=static_library" "--module=/home/vcap/app/.java-buildpack/tomcat/temp/builder/sap.nodejs/builds/build-6798269379419657313/myjabber/node_modules/grpc/src/node/extension_binary/node-v57-linux-x64-glibc/grpc_node.node" "--module_name=grpc_node" "--module_path=/home/vcap/app/.java-buildpack/tomcat/temp/builder/sap.nodejs/builds/build-6798269379419657313/myjabber/node_modules/grpc/src/node/extension_binary/node-v57-linux-x64-glibc" "--napi_version=1" "--node_abi_napi=napi" "--napi_build_version=0" "--node_napi_label=node-v57"gyp ERR! cwd /home/vcap/app/.java-buildpack/tomcat/temp/builder/sap.nodejs/builds/build-6798269379419657313/myjabber/node_modules/grpcgyp ERR! node -v v8.9.1gyp ERR! node-gyp -v v3.6.2gyp ERR! not ok node-pre-gyp ERR! build error node-pre-gyp ERR! stack Error: Failed to execute '/home/vcap/app/.java-buildpack/tomcat/temp/nodejsbin5846029318158714442/node-v8.9.1-linux-x64/bin/node /home/vcap/app/.java-buildpack/tomcat/temp/nodejsbin5846029318158714442/node-v8.9.1-linux-x64/lib/node_modules/npm/node_modules/node-gyp/bin/node-gyp.js configure --fallback-to-build --library=static_library --module=/home/vcap/app/.java-buildpack/tomcat/temp/builder/sap.nodejs/builds/build-6798269379419657313/myjabber/node_modules/grpc/src/node/extension_binary/node-v57-linux-x64-glibc/grpc_node.node --module_name=grpc_node --module_path=/home/vcap/app/.java-buildpack/tomcat/temp/builder/sap.nodejs/builds/build-6798269379419657313/myjabber/node_modules/grpc/src/node/extension_binary/node-v57-linux-x64-glibc --napi_version=1 --node_abi_napi=napi --napi_build_version=0 --node_napi_label=node-v57' (1)node-pre-gyp ERR! stack at ChildProcess. (/home/vcap/app/.java-buildpack/tomcat/temp/builder/sap.nodejs/builds/build-6798269379419657313/myjabber/node_modules/grpc/node_modules/node-pre-gyp/lib/util/compile.js:83:29)node-pre-gyp ERR! stack at emitTwo (events.js:126:13)node-pre-gyp ERR! stack at ChildProcess.emit (events.js:214:7)node-pre-gyp ERR! stack at maybeClose (internal/child_process.js:925:16)node-pre-gyp ERR! stack at Process.ChildProcess._handle.onexit (internal/child_process.js:209:5)node-pre-gyp ERR! System Linux 4.15.0-39-genericnode-pre-gyp ERR! command "/home/vcap/app/.java-buildpack/tomcat/temp/nodejsbin5846029318158714442/node-v8.9.1-linux-x64/bin/node" "/home/vcap/app/.java-buildpack/tomcat/temp/builder/sap.nodejs/builds/build-6798269379419657313/myjabber/node_modules/grpc/node_modules/.bin/node-pre-gyp" "install" "--fallback-to-build" "--library=static_library"node-pre-gyp ERR! cwd /home/vcap/app/.java-buildpack/tomcat/temp/builder/sap.nodejs/builds/build-6798269379419657313/myjabber/node_modules/grpcnode-pre-gyp ERR! node -v v8.9.1node-pre-gyp ERR! node-pre-gyp -v v0.12.0node-pre-gyp ERR! not ok Failed to execute '/home/vcap/app/.java-buildpack/tomcat/temp/nodejsbin5846029318158714442/node-v8.9.1-linux-x64/bin/node /home/vcap/app/.java-buildpack/tomcat/temp/nodejsbin5846029318158714442/node-v8.9.1-linux-x64/lib/node_modules/npm/node_modules/node-gyp/bin/node-gyp.js configure --fallback-to-build --library=static_library --module=/home/vcap/app/.java-buildpack/tomcat/temp/builder/sap.nodejs/builds/build-6798269379419657313/myjabber/node_modules/grpc/src/node/extension_binary/node-v57-linux-x64-glibc/grpc_node.node --module_name=grpc_node --module_path=/home/vcap/app/.java-buildpack/tomcat/temp/builder/sap.nodejs/builds/build-6798269379419657313/myjabber/node_modules/grpc/src/node/extension_binary/node-v57-linux-x64-glibc --napi_version=1 --node_abi_napi=napi --napi_build_version=0 --node_napi_label=node-v57' (1)npm ERR! code ELIFECYCLEnpm ERR! errno 1npm ERR! [email protected] install: node-pre-gyp install --fallback-to-build --library=static_librarynpm ERR! Exit status 1npm ERR! npm ERR! Failed at the [email protected] install script.npm ERR! This is probably not a problem with npm. There is likely additional logging output above.npm ERR! A complete log of this run can be found in:npm ERR! /home/vcap/app/META-INF/cache/8.9.1/.npm/_logs/2019-01-13T12_05_22_461Z-debug.log
4:05:17 PM (Builder) Build of /CiscoJabber/myjabber failed.

Hi,

I would like to consume this module from npm registry. But npm install fails. Is this available in repository?

Regards,
Jain

First of all: thanks for that library! We find it useful and are happy to have it.

Context

We try to use structured logging wherever possible and favour that al lot over string interpolation for the log messages. This allows us to search and analyse logs far more easy.
I.e.

// better
logger.info("Thingy created", { user: userId, thingy: { foo, bar }});
// than
logger.info(`User ${userId} created a Thingy with foo "${foo}" and bar "${bar}`);

So, we've made extensive use of those custom_fileds with your library in version 5.3.2. We've even written a small wrapper to make this simpler for us.

Thus, we were very pleased with seeing that version 6.0.0 introduced basically exactly what we've used our wrapper for: child loggers and better support for custom fields.

Problem

Since we make heavy use of these custom fields, for us it's a huge overhead to register them all with registerCustomFields first. We could do this in our wrapper dynamically, but this would be a ugly workaround.

Request

We would to be able to turn off the requirement to register all possible custom fields in order for them to be logged. We don't care how exactly this would happen, as long as it's a one time action (potentially per logger).

We could imagine this could be done either globally (requireCustomFieldRegistration = false) or per logger (logger.setRequireCustomFieldRegistration(false)).

Are you fine with this?

If yes, we would be happy. We could open a PR if you like.
If no, we would rather stay with version 5, because there everything still works for us. However, it would be sad if we miss other features in newer versions then.

When trying to send 10000 requests with delay of 10ms between each request, memory consumption increases from less than 10 MB to 100MB and doesn't decrease afterwards. It was tested on code sample at https://github.com/SAP/cf-nodejs-logging-support#with-nodejs-http

We implemented a polling in our server, so we actually generate there we generate requests which do not originate from any other incoming requests.
I would love if i could now still generate or set a correlation id for the logger for our req object.

Is this somehow possible?

Hi,
I want to use this lib in our Nodejs application. We use @sap/logging before.
I found an issue from test, It seems new lib can't set a loggerCategory for each log.
So the "layer" property in log always shows: [NODEJS]
What I want is layer property can show which node js file is writing the log because our project has many node js files.
If I can see the node js file name from layer, it's very helpful for our debug and monitoring.

current logger is:
{"component_type":"application","component_id":"57e998ea-5b1b-4297-9f6f-c20cece7f93f","component_name":"mobile-approuter","component_instance":0,"layer":"[NODEJS]","organization_name":"org1","organization_id":"1070e5be-6b4d-4ae1-928b-75c5e909e9d2","space_name":"space1","space_id":"2a177026-846f-4a9d-92bf-d80b1c38fe95","container_id":"10.0.138.80","logger":"nodejs-logger","source_instance":0,"written_at":"2020-11-27T08:18:23.474Z","written_ts":1606465103474000000,"level":"warn","correlation_id":"cbc2654f-1c35-45d0-96fc-f32efac20986","tenant_id":"cbc2654f-1c35","tenant_subdomain":"-","request_id":"","msg":"warn working","type":"log"}

I want log like this:
{"component_type":"application","component_id":"57e998ea-5b1b-4297-9f6f-c20cece7f93f","component_name":"mobile-approuter","component_instance":0,"layer":"/mobile-approuter/cookie-handler","organization_name":"org1","organization_id":"1070e5be-6b4d-4ae1-928b-75c5e909e9d2","space_name":"space1","space_id":"2a177026-846f-4a9d-92bf-d80b1c38fe95","container_id":"10.0.138.80","logger":"nodejs-logger","source_instance":0,"written_at":"2020-11-27T08:18:23.474Z","written_ts":1606465103474000000,"level":"warn","correlation_id":"cbc2654f-1c35-45d0-96fc-f32efac20986","tenant_id":"cbc2654f-1c35","tenant_subdomain":"-","request_id":"","msg":"warn working","type":"log"}

Hi,

I had a CF nodejs application and binds it to the application log services.

// sample code
const logger = require('cf-nodejs-logging-support');
logger.error('some message');

In Kibana Application Log, I can see msg: 'some message' which is good.
However some properties are hard-coded such as logger: 'nodejs-logger' and layer: '[NODEJS]'.
They are pre-set in config.js.

Is there any way I can overwrite those hard-coded values, or the library exposes API to set them?

Regards,
Simon

Hi,

is it really required to have a dependency on npm?

This adds a load of code to any package using cf-nodejs-logging-support.

Maybe you want to have it as devDependency only?

It was introduced by: 14d54f8

Now that child loggers are supported in this nifty little module, would it be possible to have a provision to define a custom log pattern per child logger?
I am expecting something like:

const globalLogger = require('cf-nodejs-logging-support');
// pattern for global logging
globalLogger.setLogPattern(
  '{{written_at}}  {{type}} - {{level}} - {{msg}}'
);
const childLogger = globalLogger.createLogger();
child.setLogPattern(
  '{{written_at}}  {{type}} - {{level}} - {{msg}} - {{custom_fields}}'
);

Where can I find release tags for this project ?
Or do you use a different way to identify releases ?

Facilitating nodes util.format adds colors for different data types.
The respective ANSI codes work well with the most consoles but impair the readability of the messages when analyzed otherwise. This applies for exports but also for logging analyzers like the Elastic stack often used together with CloudFoundry.

Currently, the workaround would be stringifying all arguments given to a logger or removing the color codes afterwards.
To avoid this unnecessary processing, it would be beneficial to make the coloring optional or customizable.
This could easily be achieved by adding a function like:

var setColors(nodeUtilInspectStyles) {
    util.inspect.styles = nodeUtilInspectStyles;
}

or exposing the styles obejct directly.

Will the custom logs show up in the kibana application log with correlation id?

Hi,

This page describes organization_id and organization_name (US English), but the logging library outputs organisation_id and organisation_name (British English). Which of the 2 types of spelling is actually correct in terms of what CF expects?

Reference

Thanks a lot

I set custom fields for global logger, it works well
var log = require('cf-nodejs-logging-support');
log.registerCustomFields(["field1", "field2", "field3"]);
log.info("nodejs log test",
{
"field1": "value1",
"field2": "value2"
}
);
the custom fields log info is correct "#cf":{"string":[{"k":"field1","v":"value1","i":0},{"k":"field2","v":"value2","i":1}]}

but if I use request logger, like this:
var log = require('cf-nodejs-logging-support');
log.registerCustomFields(["field1", "field2", "field3"]);
req.logger.info("nodejs log test",
{
"field1": "value1",
"field2": "value2"
}
);
the custom fields log info is this: "field1":"value1","field2":"value2"
so I wonder the request logger didn't output custom fields by correct format

I am using the latest version (1.0.1) of cf-nodejs-logging-support.
When calling:

logger.logMessage('Destroy cache store ...');

I get the following output:

{"written_at":"2017-03-06T19:09:53.950Z","written_ts":265924284998036,"component_type":"application","component_id":"-","compone
nt_name":"-","component_instance":"0","layer":"[NODEJS]","space_name":"-","space_id":"-","source_instance":"0","container_id":"-
","logger":"nodejs-logger","msg":"","type":"log","custom_fields":{"0":"Destroy cache store ..."}}

I was expecting to see "msg": "Destroy cache store ..." instead of being empty.
Although custom_fields contains the log message, this is not an option.

Can you please advise?

Hello,

Two questions on custom fields:

1. The documentation specifies that (registered) custom fields are part of the custom_fields property in the resulting JSON. However, the specification does not mention that property.

2. If the object containing custom fields also contains properties that are not registered as custom fields, these are put on the root level in the resulting JSON. Is this intended?

Hi CF-Logging-Team,

in Java (especially SLF4j) logger method names typically already include log severity, e.g. logger.info(message), etc. The same applies for some Node logging libs, e.g. Winston.

It would be great if you could offer similar methods in your Node lib, as well. Currently, there is only the possibility to log via logger.logMessage(severity,message,custom_fields).

Some of my colleagues implemented a small express middleware as workaround, which does this in the following way:

const log = (req, res, next) => {
  req.logger = {
    log: (level, msg, custom_fields) => {
      req.getCorrelationObject().logMessage(level, msg, custom_fields);
    },
    silly: (msg, custom_fields) => {
      req.getCorrelationObject().logMessage('silly', msg, custom_fields);
    },
    debug: (msg, custom_fields) => {
      req.getCorrelationObject().logMessage('debug', msg, custom_fields);
    },
    verbose: (msg, custom_fields) => {
      req.getCorrelationObject().logMessage('verbose', msg, custom_fields);
    },
    info: (msg, custom_fields) => {
      req.getCorrelationObject().logMessage('info', msg, custom_fields);
    },
    warn: (msg, custom_fields) => {
      req.getCorrelationObject().logMessage('warn', msg, custom_fields);
    },
    error: (msg, custom_fields) => {
      req.getCorrelationObject().logMessage('error', msg, custom_fields);
    }
  };
  next();
};

Thank you in advance and best regards,
Mario

Currently I have a use case of using the cf-nodejs-logging-support module to produce logs to Kibana on CF in my MTA. The application is secured via XSUAA and is using passport JWT strategy for authentication via the @sap/xssec module, which I think (hope?) will include login details for remote_user.

Thinking that, I set the LOG_REMOTE_USER env var to true according to the README, but I am still getting just a dash in the records on Kibana. Looking at this module's source code reveals that the value is hardcoded in config.js:

    }, {
        name: "remote_user",
        mandatory: true,
        envVarSwitch: "LOG_REMOTE_USER",
        source: {
            type: "static",
            value: "-"
        }
    }, {

So although documented, it really doesn't work. I'd suggest to either implement the feature, or at least correct the README to say the feature doesn't work. If there is other ways to log the user name for E2E trace purposes, please let me know too. Thank you.

hi experts,

I am using cf-nodejs-logging-support, v3.0.6 in node application, I am using express, but didn't add this lib as a middleware, the problem is I can still see log entries for network requests, do you have any idea with this?

var express = require('express');
var bodyParser = require('body-parser');
var xsenv = require('@sap/xsenv');
var xssec = require('@sap/xssec');
var log = require('cf-nodejs-logging-support');

var app = express();
passport.use(new xssec.JWTStrategy(xsenv.getServices({uaa:{tag:'xsuaa'}}).uaa));
app.use(bodyParser.json());
app.use(passport.initialize());
app.use( passport.authenticate('JWT', {session: false}));
var urlencodedParser = bodyParser.urlencoded({ extended: false });

//app.use(log.logNetwork);  <- this middleware is not used

Hello,

in the minimal example the following coding is mentioned:

req.logMessage("info", "Hello World will be send");

Shouldn't it be
log.logMessage("info", "Hello World will be send");

Thanks and kind regards,
Matthias

Hi,

we want to do analysis over integer values from custom fields using Kibana. But Kibana recognizes the value as string (which cannot be changed) and it is not possible to build charts on it.

There reason for this is, that the logger converts any value of a custom field into a string using JSON.stringify().

Can you change the code so the logger will keep numbers as numbers. Logstash/Kibana should be able to handle this correctly.

It happens in cf-nodejs-logging-support-core/log-core.js:

            if (!((typeof customFields[key]) == "string")) {
                logObject.custom_fields[key] = JSON.stringify(customFields[key]);
            } else {
                logObject.custom_fields[key] = customFields[key];
            }

Thanks & Best regards,
Uwe Klinger
SAP SE

Hi,

Use case: we have 2 applications - a producer and a consumer that communicate using messaging (like RabbitMQ).
When the consumer receives a message, this can trigger several async operations. Before fully processing the first message (during which the consumer application logs), a new message is received (which also logs). It would be handy to have the request_id in the logs so one can distinguish between logs logged during the processing of the first message and entries logged during the processing of the second message. Or in other words, messages can be treated as a kind of requests, but not an HTTP one.

Processing a message can be a part of a single transaction across multiple applications. It would be handy to have correlation_id in the request independent logs to distinguish between logs belonging to different transactions. The user will need a way to set it.

It is handy to have both request_id and correlation_id instead of just correlation_id for example, since (for some reason) the consumer may receive 2 messages that belong to the same logical transaction.

Regarding implementation - since the consumer application can receive 2 messages almost simultaneously and to process them (for example, every message triggers several async operations) almost simultaneously, then there need to be 2 different log objects and not a single one that is shared, because the different ids are state of the logger object.

I am not requesting such a feature, this is just something to consider.

Best regards
Petar

Currently using the logger in a back-end service deployed to CF. Version v5.3.2 works perfectly .
Unfortunately, latest version seems to throw an undefined error for this.logMessage . Tracing the source to \node_modules\cf-nodejs-logging-support\cf-nodejs-logging-support-winston\winston-transport.js:20:18 .
Would like to use latest for added contextual loggers and custom field registration.

Description

We are using the cf-nodejs-logging-support 5.3.2, but I have checked that the latest version has the same problem.

On our production on CF we are having a problem: when we do a request to a particular server and it returns 500 response, the logger is trying to print the error message and it contains the circular JSON (the server response), and the logger crushes our server with this error:

   2020-03-30T09:35:59.66+0200 [APP/PROC/WEB/0] OUT {"error":{},"level":"error","message":"uncaughtException: Converting circular structure to JSON\n    --> starting at
 object with constructor 'ClientRequest'\n    |     property 'socket' -> object with constructor 'TLSSocket'\n  
  --- property '_httpMessage' closes the circle\nTypeError: Converting circular structure to JSON\n    --> 
starting at object with constructor 'ClientRequest'\n    |     property 'socket' -> object with constructor 
'TLSSocket'\n    --- property '_httpMessage' closes the circle\n    at JSON.stringify (<anonymous>)\n    at 
logMessage (/home/vcap/app/node_modules/cf-nodejs-logging-support/cf-nodejs-logging-support-
core/log-core.js:377:53)\n    at /home/vcap/app/node_modules/cf-nodejs-logging-support/cf-nodejs-
logging-support-core/log-core.js:29:24\n    at CloudFormationBasedLogger.log 
(/home/vcap/app/src/driven-port-implementation/logger/cf-nodejs-logging-support-logger.ts
:57:7)\n    at CloudFormationBasedLogger.error (/home/vcap/app/src/driven-port-
implementation/logger/cf-nodejs-logging-support-logger.ts:37:10)\n    at JwtCheckingSequence.handle 
(/home/vcap/app/src/drivers/loopback-webapp/jwt-checking-sequence.ts:71:14)\n    at 
processTicksAndRejections (internal/process/task_queues.js:94:5)\n    at HttpHandler._handleRequest 
(/home/vcap/app/node_modules/@loopback/rest/src/http-handler.ts:78:5)","stack":"TypeError: Converting
 circular structure to JSON\n    --> starting at object with constructor 'ClientRequest'\n    |     property 
'socket' -> object with constructor 'TLSSocket'\n    --- property '_httpMessage' closes the circle\n    at
 JSON.stringify (<anonymous>)\n    at logMessage (/home/vcap/app/node_modules/cf-nodejs-logging-
support/cf-nodejs-logging-support-core/log-core.js:377:53)\n    at /home/vcap/app/node_modules/cf-
nodejs-logging-support/cf-nodejs-logging-support-core/log-core.js:29:24\n    at 
CloudFormationBasedLogger.log (/home/vcap/app/src/driven-port-implementation/logger/cf-nodejs-
logging-support-logger.ts:57:7)\n    at CloudFormationBasedLogger.error (/home/vcap/app/src/driven-
port-implementation/logger/cf-nodejs-logging-support-logger.ts:37:10)\n    at 
JwtCheckingSequence.handle (/home/vcap/app/src/drivers/loopback-webapp/jwt-checking-
sequence.ts:71:14)\n    at processTicksAndRejections (internal/process/task_queues.js:94:5)\n    at 
HttpHandler._handleRequest (/home/vcap/app/node_modules/@loopback/rest/src/http-handler.ts:78:5)"

Steps to reproduce:

Download repo and run this code in the root folder:

const logMessage = require("./cf-nodejs-logging-support-core/log-core").logMessage;

const a = { name: 'Text1' };
const b = { name: 'Text2', sibling: a };
a.sibling = b;

logMessage("info", a);

You will get an error:

/Users/I521237/programming/cf-nodejs-logging-support/cf-nodejs-logging-support-core/log-core.js:523
            value = JSON.stringify(value);
                         ^

TypeError: Converting circular structure to JSON
    --> starting at object with constructor 'Object'
    |     property 'sibling' -> object with constructor 'Object'
    --- property 'sibling' closes the circle
    at JSON.stringify (<anonymous>)
    at writeCustomFields (/Users/I521237/programming/cf-nodejs-logging-support/cf-nodejs-logging-support-core/log-core.js:523:26)
    at logMessage (/Users/I521237/programming/cf-nodejs-logging-support/cf-nodejs-logging-support-core/log-core.js:407:5)
    at Object.<anonymous> (/Users/I521237/programming/cf-nodejs-logging-support/cf-nodejs-logging-support-core/x.js:7:1)
    at Module._compile (internal/modules/cjs/loader.js:959:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:995:10)
    at Module.load (internal/modules/cjs/loader.js:815:32)
    at Function.Module._load (internal/modules/cjs/loader.js:727:14)
    at Function.Module.runMain (internal/modules/cjs/loader.js:1047:10)
    at internal/main/run_main_module.js:17:11

How to fix it

In order to fix it, we can use this kind of library: https://www.npmjs.com/package/json-stringify-safe instead of just using JSON.stringify or just try/catch the operation of stringifying.

Let me know if you want me to write the PR or you can do it yourself.

IF you don't think this bug should be fixed, then let me know how we can deal with the problem of this unhandled error that crushes our serever.