logging common data simply

classic Classic list List threaded Threaded
14 messages Options
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

logging common data simply

Shanholtz, Jeff

I have a scenario where I have 1, 2, or 3 pieces of data (guids) which I want to to log with all messages in order to track records as they traverse their way through a series of microservices.

 

Currently I’ve written my own wrapper class with my own debug, info, warn, error methods that take these 3 parameters, followed by the message field, followed by the optional parameters.

 

There must be a better way, plus this has the disadvantage of rendering the line number useless in log messages because the line numbers are the line numbers from my log wrapper class, not the actual code doing the logging.

 

What is the best way to handle this scenario? Googling has failed me, as has the FAQ, but it’s probably because I don’t know the right terms to search for. I’m using log4j2 as the underlying logger FWIW.

 

Here’s a simplified version of my log wrapper (i.e. most methods stripped out because they are redundant for the purpose of this question):

 

public class Log {
   
private Logger logger;

   
public Log(Class clazz) {
       
logger = LoggerFactory.getLogger(clazz);
    }

   
public void info(Object xGuid, Object yGuid, String zGuid, String message, Object... args) {
        
logger.info(guidifiedMessage(xGuid, yGuid, zGuid, message), args);
    }
}

 

The “guidifiedMessage” method just prefixes the message string with whatever guids are present.

 

So is there a better way? Or if not, is there at least a way to get the line number specified in my log4j properties to reflect the caller of this Log class rather than the line within the Log class?


_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: logging common data simply

Elliot Huntington
I could be wrong, but I think you are looking for MDC.

https://www.slf4j.org/manual.html

See the section titled "Mapped Diagnostic Context (MDC) support"


On Sat, Feb 25, 2017 at 12:34 PM, Shanholtz, Jeff <[hidden email]> wrote:

I have a scenario where I have 1, 2, or 3 pieces of data (guids) which I want to to log with all messages in order to track records as they traverse their way through a series of microservices.

 

Currently I’ve written my own wrapper class with my own debug, info, warn, error methods that take these 3 parameters, followed by the message field, followed by the optional parameters.

 

There must be a better way, plus this has the disadvantage of rendering the line number useless in log messages because the line numbers are the line numbers from my log wrapper class, not the actual code doing the logging.

 

What is the best way to handle this scenario? Googling has failed me, as has the FAQ, but it’s probably because I don’t know the right terms to search for. I’m using log4j2 as the underlying logger FWIW.

 

Here’s a simplified version of my log wrapper (i.e. most methods stripped out because they are redundant for the purpose of this question):

 

public class Log {
   
private Logger logger;

   
public Log(Class clazz) {
       
logger = LoggerFactory.getLogger(clazz);
    }

   
public void info(Object xGuid, Object yGuid, String zGuid, String message, Object... args) {
        
logger.info(guidifiedMessage(xGuid, yGuid, zGuid, message), args);
    }
}

 

The “guidifiedMessage” method just prefixes the message string with whatever guids are present.

 

So is there a better way? Or if not, is there at least a way to get the line number specified in my log4j properties to reflect the caller of this Log class rather than the line within the Log class?


_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user


_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: logging common data simply

Elliot Huntington

On Sat, Feb 25, 2017 at 1:01 PM, Elliot Huntington <[hidden email]> wrote:
I could be wrong, but I think you are looking for MDC.

https://www.slf4j.org/manual.html

See the section titled "Mapped Diagnostic Context (MDC) support"


On Sat, Feb 25, 2017 at 12:34 PM, Shanholtz, Jeff <[hidden email]> wrote:

I have a scenario where I have 1, 2, or 3 pieces of data (guids) which I want to to log with all messages in order to track records as they traverse their way through a series of microservices.

 

Currently I’ve written my own wrapper class with my own debug, info, warn, error methods that take these 3 parameters, followed by the message field, followed by the optional parameters.

 

There must be a better way, plus this has the disadvantage of rendering the line number useless in log messages because the line numbers are the line numbers from my log wrapper class, not the actual code doing the logging.

 

What is the best way to handle this scenario? Googling has failed me, as has the FAQ, but it’s probably because I don’t know the right terms to search for. I’m using log4j2 as the underlying logger FWIW.

 

Here’s a simplified version of my log wrapper (i.e. most methods stripped out because they are redundant for the purpose of this question):

 

public class Log {
   
private Logger logger;

   
public Log(Class clazz) {
       
logger = LoggerFactory.getLogger(clazz);
    }

   
public void info(Object xGuid, Object yGuid, String zGuid, String message, Object... args) {
        
logger.info(guidifiedMessage(xGuid, yGuid, zGuid, message), args);
    }
}

 

The “guidifiedMessage” method just prefixes the message string with whatever guids are present.

 

So is there a better way? Or if not, is there at least a way to get the line number specified in my log4j properties to reflect the caller of this Log class rather than the line within the Log class?


_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user



_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: logging common data simply

Joachim Durchholz
In reply to this post by Shanholtz, Jeff
On 25.02.2017 20:34, Shanholtz, Jeff wrote:
> I have a scenario where I have 1, 2, or 3 pieces of data (guids) which I
> want to to log with all messages in order to track records as they
> traverse their way through a series of microservices.

That's a common scenario.

> Currently I’ve written my own wrapper class with my own debug, info,
> warn, error methods that take these 3 parameters, followed by the
> message field, followed by the optional parameters.

Any library function that you call will still use the original loggers
so you won't know with which of the guids some log message from deep
inside a call is associated.
This is a real PITA if you have multiple requests executing in parallel.

> There must be a better way, plus this has the disadvantage of rendering
> the line number useless in log messages because the line numbers are the
> line numbers from my log wrapper class, not the actual code doing the
> logging.

Elliot has the start of the trail right: Use an MDC.
The other half of the trail is that formatters have an escape code for
extracting data from the MDC (%m if I remember correctly).

HTH
Jo
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: logging common data simply

Ceki Gulcu

Regarding wrong line numbers shown with your log wrapper, with logback
you can fix the issue by calling:

LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
lc.getFrameworkPackages().add("package of log wrapper");

Best regards,

--
Ceki

On 2/25/2017 21:15, Joachim Durchholz wrote:

> On 25.02.2017 20:34, Shanholtz, Jeff wrote:
>> I have a scenario where I have 1, 2, or 3 pieces of data (guids) which I
>> want to to log with all messages in order to track records as they
>> traverse their way through a series of microservices.
>
> That's a common scenario.
>
>> Currently I’ve written my own wrapper class with my own debug, info,
>> warn, error methods that take these 3 parameters, followed by the
>> message field, followed by the optional parameters.
>
> Any library function that you call will still use the original loggers
> so you won't know with which of the guids some log message from deep
> inside a call is associated.
> This is a real PITA if you have multiple requests executing in parallel.
>
>> There must be a better way, plus this has the disadvantage of rendering
>> the line number useless in log messages because the line numbers are the
>> line numbers from my log wrapper class, not the actual code doing the
>> logging.
>
> Elliot has the start of the trail right: Use an MDC.
> The other half of the trail is that formatters have an escape code for
> extracting data from the MDC (%m if I remember correctly).
>
> HTH
> Jo
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: logging common data simply

Shanholtz, Jeff
Thanks for the quick responses everyone! Now I know what to start researching. :)

-----Original Message-----
From: slf4j-user [mailto:[hidden email]] On Behalf Of Ceki Gülcü
Sent: Saturday, February 25, 2017 12:37 PM
To: User list for the slf4j project <[hidden email]>
Subject: Re: [slf4j-user] logging common data simply


Regarding wrong line numbers shown with your log wrapper, with logback you can fix the issue by calling:

LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
lc.getFrameworkPackages().add("package of log wrapper");

Best regards,

--
Ceki

On 2/25/2017 21:15, Joachim Durchholz wrote:

> On 25.02.2017 20:34, Shanholtz, Jeff wrote:
>> I have a scenario where I have 1, 2, or 3 pieces of data (guids)
>> which I want to to log with all messages in order to track records as
>> they traverse their way through a series of microservices.
>
> That's a common scenario.
>
>> Currently I’ve written my own wrapper class with my own debug, info,
>> warn, error methods that take these 3 parameters, followed by the
>> message field, followed by the optional parameters.
>
> Any library function that you call will still use the original loggers
> so you won't know with which of the guids some log message from deep
> inside a call is associated.
> This is a real PITA if you have multiple requests executing in parallel.
>
>> There must be a better way, plus this has the disadvantage of
>> rendering the line number useless in log messages because the line
>> numbers are the line numbers from my log wrapper class, not the
>> actual code doing the logging.
>
> Elliot has the start of the trail right: Use an MDC.
> The other half of the trail is that formatters have an escape code for
> extracting data from the MDC (%m if I remember correctly).
>
> HTH
> Jo
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: logging common data simply

Matt Sicker
Generally, what you're describing isn't necessarily the MDC. It sounds more like distributed tracing:


The MDC/ThreadContext APIs are useful for maintaining contextual data within threads, but if you want to propagate between microservices or do any sort of correlation, you'll need to standardize ways on passing that context data over HTTP, JMS, etc. A couple projects exist out there that can instrument your IPC with the relevant ids and will send log messages to a Zipkin collector (or similar):


If this is what you're working on, then I hope this helps! I'm working on a very similar project at my work right now, so this is all fresh.

On 25 February 2017 at 14:40, Shanholtz, Jeff <[hidden email]> wrote:
Thanks for the quick responses everyone! Now I know what to start researching. :)

-----Original Message-----
From: slf4j-user [mailto:[hidden email]] On Behalf Of Ceki Gülcü
Sent: Saturday, February 25, 2017 12:37 PM
To: User list for the slf4j project <[hidden email]>
Subject: Re: [slf4j-user] logging common data simply


Regarding wrong line numbers shown with your log wrapper, with logback you can fix the issue by calling:

LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
lc.getFrameworkPackages().add("package of log wrapper");

Best regards,

--
Ceki

On 2/25/2017 21:15, Joachim Durchholz wrote:
> On <a href="tel:25.02.2017%2020" value="+12502201720">25.02.2017 20:34, Shanholtz, Jeff wrote:
>> I have a scenario where I have 1, 2, or 3 pieces of data (guids)
>> which I want to to log with all messages in order to track records as
>> they traverse their way through a series of microservices.
>
> That's a common scenario.
>
>> Currently I’ve written my own wrapper class with my own debug, info,
>> warn, error methods that take these 3 parameters, followed by the
>> message field, followed by the optional parameters.
>
> Any library function that you call will still use the original loggers
> so you won't know with which of the guids some log message from deep
> inside a call is associated.
> This is a real PITA if you have multiple requests executing in parallel.
>
>> There must be a better way, plus this has the disadvantage of
>> rendering the line number useless in log messages because the line
>> numbers are the line numbers from my log wrapper class, not the
>> actual code doing the logging.
>
> Elliot has the start of the trail right: Use an MDC.
> The other half of the trail is that formatters have an escape code for
> extracting data from the MDC (%m if I remember correctly).
>
> HTH
> Jo
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user



--
Matt Sicker <[hidden email]>

_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: logging common data simply

Shanholtz, Jeff

No, it sounds like what you’re describing isn’t what I’m seeking. I’m talking purely about logging. The comment about multiple microservices was tangential. We’re using kafka for communicating between the microservices. Thanks for the thought though!

 

Upon investigating MDC, I don’t think it’ll work very well for my scenario. I’m not looking for something that is essentially static or at least static over some period of time. I’m looking for more of a local variable/transient MDC concept. In other words, if I were to set MDC properties in one method and then call another method, that other method may want to log different values for the properties (or none of the properties for that matter).

 

Could I make it work somehow? Probably. I just messed around with one idea I had. It would definitely require a standardized approach to logging and avoiding use of loggers without doing some MDC interaction or else log messages which shouldn’t have one or more of the guids will get them anyway.

 

Unless there’s another way to approach my problem that doesn’t have the drawbacks I’m describing, I might be better off sticking with my wrapper approach and trying Ceki’s solution for line numbers.

 

FWIW here’s the attempt I made at using MDC for my purpose but then I realized the potential for problems if someone uses a logger without this:

 

public class GuidLog {
   
public static Log guids(Object xGuid, Object yGuid, String zGuid, Log log) {
        MDC.put(
"xGuid", xGuid.toString());
        MDC.put(
"yGuid", yGuid.toString());
        MDC.put(
"zGuid", zGuid.toString());
       
return log;
    }
}

GuidLog.guids(xGuid, yGuid, zGuid, logger).info("My log message");

 

 

From: slf4j-user [mailto:[hidden email]] On Behalf Of Matt Sicker
Sent: Saturday, February 25, 2017 1:55 PM
To: User list for the slf4j project <[hidden email]>
Subject: Re: [slf4j-user] logging common data simply

 

Generally, what you're describing isn't necessarily the MDC. It sounds more like distributed tracing:

 

 

The MDC/ThreadContext APIs are useful for maintaining contextual data within threads, but if you want to propagate between microservices or do any sort of correlation, you'll need to standardize ways on passing that context data over HTTP, JMS, etc. A couple projects exist out there that can instrument your IPC with the relevant ids and will send log messages to a Zipkin collector (or similar):

 

 

If this is what you're working on, then I hope this helps! I'm working on a very similar project at my work right now, so this is all fresh.

 

On 25 February 2017 at 14:40, Shanholtz, Jeff <[hidden email]> wrote:

Thanks for the quick responses everyone! Now I know what to start researching. :)


-----Original Message-----
From: slf4j-user [mailto:[hidden email]] On Behalf Of Ceki Gülcü
Sent: Saturday, February 25, 2017 12:37 PM
To: User list for the slf4j project <[hidden email]>
Subject: Re: [slf4j-user] logging common data simply


Regarding wrong line numbers shown with your log wrapper, with logback you can fix the issue by calling:

LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
lc.getFrameworkPackages().add("package of log wrapper");

Best regards,

--
Ceki

On 2/25/2017 21:15, Joachim Durchholz wrote:
> On <a href="tel:25.02.2017%2020">25.02.2017 20:34, Shanholtz, Jeff wrote:
>> I have a scenario where I have 1, 2, or 3 pieces of data (guids)
>> which I want to to log with all messages in order to track records as
>> they traverse their way through a series of microservices.
>
> That's a common scenario.
>
>> Currently I’ve written my own wrapper class with my own debug, info,
>> warn, error methods that take these 3 parameters, followed by the
>> message field, followed by the optional parameters.
>
> Any library function that you call will still use the original loggers
> so you won't know with which of the guids some log message from deep
> inside a call is associated.
> This is a real PITA if you have multiple requests executing in parallel.
>
>> There must be a better way, plus this has the disadvantage of
>> rendering the line number useless in log messages because the line
>> numbers are the line numbers from my log wrapper class, not the
>> actual code doing the logging.
>
> Elliot has the start of the trail right: Use an MDC.
> The other half of the trail is that formatters have an escape code for
> extracting data from the MDC (%m if I remember correctly).
>
> HTH
> Jo
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user



 

--

Matt Sicker <[hidden email]>


_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: logging common data simply

Matt Sicker
In log4j-api, you could create your own Message class that has that data and log via that.

Otherwise, it sounds like you're getting into scope rules and such regarding the MDC. You could try the NDC for a nested version, but that's a stack instead of a map, so you'll have to wrap your values in a sort of tuple.

On 25 February 2017 at 18:14, Shanholtz, Jeff <[hidden email]> wrote:

No, it sounds like what you’re describing isn’t what I’m seeking. I’m talking purely about logging. The comment about multiple microservices was tangential. We’re using kafka for communicating between the microservices. Thanks for the thought though!

 

Upon investigating MDC, I don’t think it’ll work very well for my scenario. I’m not looking for something that is essentially static or at least static over some period of time. I’m looking for more of a local variable/transient MDC concept. In other words, if I were to set MDC properties in one method and then call another method, that other method may want to log different values for the properties (or none of the properties for that matter).

 

Could I make it work somehow? Probably. I just messed around with one idea I had. It would definitely require a standardized approach to logging and avoiding use of loggers without doing some MDC interaction or else log messages which shouldn’t have one or more of the guids will get them anyway.

 

Unless there’s another way to approach my problem that doesn’t have the drawbacks I’m describing, I might be better off sticking with my wrapper approach and trying Ceki’s solution for line numbers.

 

FWIW here’s the attempt I made at using MDC for my purpose but then I realized the potential for problems if someone uses a logger without this:

 

public class GuidLog {
   
public static Log guids(Object xGuid, Object yGuid, String zGuid, Log log) {
        MDC.put(
"xGuid", xGuid.toString());
        MDC.put(
"yGuid", yGuid.toString());
        MDC.put(
"zGuid", zGuid.toString());
       
return log;
    }
}

GuidLog.guids(xGuid, yGuid, zGuid, logger).info("My log message");

 

 

From: slf4j-user [mailto:[hidden email]] On Behalf Of Matt Sicker
Sent: Saturday, February 25, 2017 1:55 PM


To: User list for the slf4j project <[hidden email]>
Subject: Re: [slf4j-user] logging common data simply

 

Generally, what you're describing isn't necessarily the MDC. It sounds more like distributed tracing:

 

 

The MDC/ThreadContext APIs are useful for maintaining contextual data within threads, but if you want to propagate between microservices or do any sort of correlation, you'll need to standardize ways on passing that context data over HTTP, JMS, etc. A couple projects exist out there that can instrument your IPC with the relevant ids and will send log messages to a Zipkin collector (or similar):

 

 

If this is what you're working on, then I hope this helps! I'm working on a very similar project at my work right now, so this is all fresh.

 

On 25 February 2017 at 14:40, Shanholtz, Jeff <[hidden email]> wrote:

Thanks for the quick responses everyone! Now I know what to start researching. :)


-----Original Message-----
From: slf4j-user [mailto:[hidden email]] On Behalf Of Ceki Gülcü
Sent: Saturday, February 25, 2017 12:37 PM
To: User list for the slf4j project <[hidden email]>
Subject: Re: [slf4j-user] logging common data simply


Regarding wrong line numbers shown with your log wrapper, with logback you can fix the issue by calling:

LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
lc.getFrameworkPackages().add("package of log wrapper");

Best regards,

--
Ceki

On 2/25/2017 21:15, Joachim Durchholz wrote:
> On <a href="tel:25.02.2017%2020" target="_blank">25.02.2017 20:34, Shanholtz, Jeff wrote:
>> I have a scenario where I have 1, 2, or 3 pieces of data (guids)
>> which I want to to log with all messages in order to track records as
>> they traverse their way through a series of microservices.
>
> That's a common scenario.
>
>> Currently I’ve written my own wrapper class with my own debug, info,
>> warn, error methods that take these 3 parameters, followed by the
>> message field, followed by the optional parameters.
>
> Any library function that you call will still use the original loggers
> so you won't know with which of the guids some log message from deep
> inside a call is associated.
> This is a real PITA if you have multiple requests executing in parallel.
>
>> There must be a better way, plus this has the disadvantage of
>> rendering the line number useless in log messages because the line
>> numbers are the line numbers from my log wrapper class, not the
>> actual code doing the logging.
>
> Elliot has the start of the trail right: Use an MDC.
> The other half of the trail is that formatters have an escape code for
> extracting data from the MDC (%m if I remember correctly).
>
> HTH
> Jo
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user



 

--

Matt Sicker <[hidden email]>


_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user



--
Matt Sicker <[hidden email]>

_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: logging common data simply

Joachim Durchholz
In reply to this post by Shanholtz, Jeff
On 26.02.2017 01:14, Shanholtz, Jeff wrote:
> Upon investigating MDC, I don’t think it’ll work very well for my
> scenario. I’m not looking for something that is essentially static or at
> least static over some period of time. I’m looking for more of a local
> variable/transient MDC concept.

MDC is thread-local, with child threads inheriting it from the parent.
I.e. it's sort-of global.

 > In other words, if I were to set MDC
> properties in one method and then call another method, that other method
> may want to log different values for the properties (or none of the
> properties for that matter).

Maybe you should talk a bit about how your GUIDs go in and out of scope.
Since we don't know about that, we cannot make any useful proposals how
to make them available to logging.

On a tangent, consider the case that some library you are calling is
emitting log messages: Do you needs your GUIDs in these messages to find
out which of them belong to the same context?
The MDC is the only option to in inject data into such log messages,
because 3rd-party library know nothing about your GUIDs, or about your
SLF4J wrapper.

> Unless there’s another way to approach my problem that doesn’t have the
> drawbacks I’m describing, I might be better off sticking with my wrapper
> approach

The wrapper is a typical code smell, that's why people are trying to
find other solutions for you.
Your use case might be the 1% where it's justified anyway. I see vague
signs that the wrapper might indeed be a solution, but that it *is*
going to make your code inflexible in some ways.

> GuidLog.guids(xGuid, yGuid, zGuid, logger).info("My log message");

Where's the advantage over

   logger.info("{}/{}/{} My log message", xGuid, yGuid, zGuid)

?

If you have lots of debug logging, the wrapper approach will force lots
of toString calls and multithreaded hashmap updates inside MDC.put even
if the log level does not cover DEBUG, so the wrapper approach would be
lower.

Regards,
Jo
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: logging common data simply

Shanholtz, Jeff
This is not a case where I want to inject "global" data into the logs. The guids are very much tied to the context of the code. For instance, all 3 guids might need to be logged at one point, then a method is called in which only the 1st guid is relevant. Once that method returns, it might be back to logging all 3 guids again. And no, I'm not concerned about calls to 3rd party libraries.

I agree that my wrapper isn't pretty which is the reason I started this topic.

You ask why is a wrapper better than just plain old logging? It is *marginally* better in that it forces a consistent log message format (important for importing into our ELK stack) and also serves as a reminder to the programmer to include the guids whenever possible.

Unfortunately Ceki's line number solution doesn't appear to apply. We're using log4j, not logback, and I haven't been able to find a similar log4j solution so far.

Thanks for the thoughts and ideas, everyone.

-----Original Message-----
From: slf4j-user [mailto:[hidden email]] On Behalf Of Joachim Durchholz
Sent: Saturday, February 25, 2017 11:49 PM
To: [hidden email]
Subject: Re: [slf4j-user] logging common data simply

On 26.02.2017 01:14, Shanholtz, Jeff wrote:
> Upon investigating MDC, I don’t think it’ll work very well for my
> scenario. I’m not looking for something that is essentially static or
> at least static over some period of time. I’m looking for more of a
> local variable/transient MDC concept.

MDC is thread-local, with child threads inheriting it from the parent.
I.e. it's sort-of global.

 > In other words, if I were to set MDC
> properties in one method and then call another method, that other
> method may want to log different values for the properties (or none of
> the properties for that matter).

Maybe you should talk a bit about how your GUIDs go in and out of scope.
Since we don't know about that, we cannot make any useful proposals how to make them available to logging.

On a tangent, consider the case that some library you are calling is emitting log messages: Do you needs your GUIDs in these messages to find out which of them belong to the same context?
The MDC is the only option to in inject data into such log messages, because 3rd-party library know nothing about your GUIDs, or about your SLF4J wrapper.

> Unless there’s another way to approach my problem that doesn’t have
> the drawbacks I’m describing, I might be better off sticking with my
> wrapper approach

The wrapper is a typical code smell, that's why people are trying to find other solutions for you.
Your use case might be the 1% where it's justified anyway. I see vague signs that the wrapper might indeed be a solution, but that it *is* going to make your code inflexible in some ways.

> GuidLog.guids(xGuid, yGuid, zGuid, logger).info("My log message");

Where's the advantage over

   logger.info("{}/{}/{} My log message", xGuid, yGuid, zGuid)

?

If you have lots of debug logging, the wrapper approach will force lots of toString calls and multithreaded hashmap updates inside MDC.put even if the log level does not cover DEBUG, so the wrapper approach would be lower.

Regards,
Jo
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: logging common data simply

Matt Sicker
The line number solution in log4j is handled like this: https://logging.apache.org/log4j/2.x/faq.html#logger-wrapper

On 27 February 2017 at 10:31, Shanholtz, Jeff <[hidden email]> wrote:
This is not a case where I want to inject "global" data into the logs. The guids are very much tied to the context of the code. For instance, all 3 guids might need to be logged at one point, then a method is called in which only the 1st guid is relevant. Once that method returns, it might be back to logging all 3 guids again. And no, I'm not concerned about calls to 3rd party libraries.

I agree that my wrapper isn't pretty which is the reason I started this topic.

You ask why is a wrapper better than just plain old logging? It is *marginally* better in that it forces a consistent log message format (important for importing into our ELK stack) and also serves as a reminder to the programmer to include the guids whenever possible.

Unfortunately Ceki's line number solution doesn't appear to apply. We're using log4j, not logback, and I haven't been able to find a similar log4j solution so far.

Thanks for the thoughts and ideas, everyone.

-----Original Message-----
From: slf4j-user [mailto:[hidden email]] On Behalf Of Joachim Durchholz
Sent: Saturday, February 25, 2017 11:49 PM
To: [hidden email]
Subject: Re: [slf4j-user] logging common data simply

On <a href="tel:26.02.2017%2001" value="+12602201701">26.02.2017 01:14, Shanholtz, Jeff wrote:
> Upon investigating MDC, I don’t think it’ll work very well for my
> scenario. I’m not looking for something that is essentially static or
> at least static over some period of time. I’m looking for more of a
> local variable/transient MDC concept.

MDC is thread-local, with child threads inheriting it from the parent.
I.e. it's sort-of global.

 > In other words, if I were to set MDC
> properties in one method and then call another method, that other
> method may want to log different values for the properties (or none of
> the properties for that matter).

Maybe you should talk a bit about how your GUIDs go in and out of scope.
Since we don't know about that, we cannot make any useful proposals how to make them available to logging.

On a tangent, consider the case that some library you are calling is emitting log messages: Do you needs your GUIDs in these messages to find out which of them belong to the same context?
The MDC is the only option to in inject data into such log messages, because 3rd-party library know nothing about your GUIDs, or about your SLF4J wrapper.

> Unless there’s another way to approach my problem that doesn’t have
> the drawbacks I’m describing, I might be better off sticking with my
> wrapper approach

The wrapper is a typical code smell, that's why people are trying to find other solutions for you.
Your use case might be the 1% where it's justified anyway. I see vague signs that the wrapper might indeed be a solution, but that it *is* going to make your code inflexible in some ways.

> GuidLog.guids(xGuid, yGuid, zGuid, logger).info("My log message");

Where's the advantage over

   logger.info("{}/{}/{} My log message", xGuid, yGuid, zGuid)

?

If you have lots of debug logging, the wrapper approach will force lots of toString calls and multithreaded hashmap updates inside MDC.put even if the log level does not cover DEBUG, so the wrapper approach would be lower.

Regards,
Jo
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user



--
Matt Sicker <[hidden email]>

_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: logging common data simply

Joachim Durchholz
In reply to this post by Shanholtz, Jeff
On 27.02.2017 17:31, Shanholtz, Jeff wrote:
> You ask why is a wrapper better than just plain old logging? It is *marginally* better in that it forces a consistent log message format (important for importing into our ELK stack) and also serves as a reminder to the programmer to include the guids whenever possible.

In that case, you can use a wrapper class like this:

public class GuidForLog {
     private GUID guid1;
     private GUID guid2;
     private GUID guid3;
     public GuidForLog(GUID guid1, GUID guid2, GUID guid3) {
         this.guid1 = guid1;
         this.guid2 = guid2;
         this.guid3 = guid3;
     }
     public GuidForLog(GUID guid1, GUID guid2) {
         this.guid1 = guid1;
         this.guid2 = guid2;
     }
     public GuidForLog(GUID guid1) {
         this.guid1 = guid1;
     }
     public String toString() {
         StringBuilder sb := new StringBuilder();
         sb.append("[");
         sb.append(guid1);
         if (guid2 != null) {
             sb.append(",");
             sb.append(guid2);
         }
         if (guid3 != null) {
             sb.append(",");
             sb.append(guid3);
         }
         sb.append("]");
     }
}

Programmers can then use it like this:

logger.info("GUID {}: foo blah blarb", new GuidForLog(guid1, guid2));

It does not make programmers think about adding the GUIDs, but it does
make sure there's a common format.
If GUID is something other than String, then this also avoids
unnecessary toString calls.


Option B:

If the number of GUIDs is known in advance for each call site, then

logger.info("GUID [{},{}]: foo blah blarb", guid1, guid2);

is still the easiest option.


_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: logging common data simply

Shanholtz, Jeff
Not a bad suggestion. I'll give that some thought but I think I like it! Thank you!

-----Original Message-----
From: slf4j-user [mailto:[hidden email]] On Behalf Of Joachim Durchholz
Sent: Tuesday, February 28, 2017 12:22 PM
To: [hidden email]
Subject: Re: [slf4j-user] logging common data simply

On 27.02.2017 17:31, Shanholtz, Jeff wrote:
> You ask why is a wrapper better than just plain old logging? It is *marginally* better in that it forces a consistent log message format (important for importing into our ELK stack) and also serves as a reminder to the programmer to include the guids whenever possible.

In that case, you can use a wrapper class like this:

public class GuidForLog {
     private GUID guid1;
     private GUID guid2;
     private GUID guid3;
     public GuidForLog(GUID guid1, GUID guid2, GUID guid3) {
         this.guid1 = guid1;
         this.guid2 = guid2;
         this.guid3 = guid3;
     }
     public GuidForLog(GUID guid1, GUID guid2) {
         this.guid1 = guid1;
         this.guid2 = guid2;
     }
     public GuidForLog(GUID guid1) {
         this.guid1 = guid1;
     }
     public String toString() {
         StringBuilder sb := new StringBuilder();
         sb.append("[");
         sb.append(guid1);
         if (guid2 != null) {
             sb.append(",");
             sb.append(guid2);
         }
         if (guid3 != null) {
             sb.append(",");
             sb.append(guid3);
         }
         sb.append("]");
     }
}

Programmers can then use it like this:

logger.info("GUID {}: foo blah blarb", new GuidForLog(guid1, guid2));

It does not make programmers think about adding the GUIDs, but it does make sure there's a common format.
If GUID is something other than String, then this also avoids unnecessary toString calls.


Option B:

If the number of GUIDs is known in advance for each call site, then

logger.info("GUID [{},{}]: foo blah blarb", guid1, guid2);

is still the easiest option.


_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Loading...