Logging API discussion
Hello. I resumed discussion about SystemLogger and Beacon here http://forum.world.st/What-the-state-of-unifying-Beacon-with-SystemLogger-td... . I plan to unify both approaches by saving traditional terminology from SystemLogger and cool features from Beacon. Let's think about logging API to log any object in the system. Most natural way is just send message #log to object itself: anObject log It would be nice replacement for Object>>logCr. But when we log some information we usually want to log it with little remark, importance level and (most important) timestamp. This information is kind of standard for logging domain. But it requires much more methods for logging API. So we need extra information to put together with objects: 1. timestamp 2. user message 3. importance level (debug, info, error, etc.) 4. whatever (process hash, process name for example) 5. sometimes it can be needed to put in log something different than object itself. (for example it can be just copy of object to not change state of log entry during app lifetime) Here is possible API based on Object extensions. It has drawbacks but it is good to think about it too: "it will put anObject in logs with default #info level" anObject log "it will put anObject in logs with default #info level and given user message" anObject logWith: 'something interesting was happened with anObject' "inside block we can put any logging domain information from application and also override content by specific representation" anObject logBy: [:logEntry | logEntry message: 'something interesting to be saved with our object' logEntry content: anotherObject] "here logs with interest about anObject will receive logEntry with anotherObject instead of anObject" And similar for different kind of levels: anObject logForDebug. anObject logForDebugWith: 'some debug message' anObject logForDebugBy: [:logEntry | ] anObject logAsError. anObject logAsError: 'object computation was wrong' anObject logAsErrorBy: [:logEntry | ] And most general: anObject logAs: LogLevel warn anObject logAs: LogLevel warn with: 'something interesting' anObject logAs: LogLevel warn by: [:logEntry | ] And in case of classic logging with strings only first expressions would be used: 'some info message' log. 'some debug message' logForDebug 'some error message' logAsError 'some warn message' logAs: LogLevel warn Problem with this approach: it pollutes Object with 12 extra methods and it can be more. So maybe it is better to use current SystemLogger API based on class Log: Log info: anObject Log info: anObject as: 'computation result' "as example" Log info: anObject as: [:logEntry | logEntry message: 'something interesting to be saved with our object logEntry content: anotherObject] Log error: anObject Log error: anObject as: 'computation was wrong'' Log error: anObject as: [:logEntry | ] Comparing to original SystemLogger versions I separate user message from object content. It makes possible to log any object with extra user message. But anyway it not feels very well IMHO. And it requires three methods for each log level. Maybe we can put this methods into LogLevel itself: Log info add: anObject Log info add: anObject as: 'computation result' Log info add: anObject as: [:logEntry | logEntry message: 'something interesting to be saved with our object logEntry content: anotherObject] Log error add: anObject Log error add: anObject as: 'computation was wrong'' Log error add: anObject as: [:logEntry | ] And we can make short version for default logging level (which can be object specific): Log add: anObject Log add: anObject as: 'computation result' Log add: anObject as: [:logEntry | ] That's all. I hope we can produce best suitable API for object logging. Then we can think how to adopt SystemLogger or Beacon for it. Also think about this API in context that we can register specific loggers for specific objects and specific importance level. Best regards, Denis
Hi Dennis,
On Apr 26, 2016, at 3:26 PM, Denis Kudriashov <dionisiydk@gmail.com> wrote:
Hello.
I resumed discussion about SystemLogger and Beacon here http://forum.world.st/What-the-state-of-unifying-Beacon-with-SystemLogger-td.... I plan to unify both approaches by saving traditional terminology from SystemLogger and cool features from Beacon.
Thanks for your effort, but as I said before, the decision was to integrate Beacon and iterate on that.
Let's think about logging API to log any object in the system. Most natural way is just send message #log to object itself:
anObject log
It would be nice replacement for Object>>logCr.
This type of usage should be discouraged in my opinion. We should instead encourage people to use typed logging signals, like we should also discourage people from using self error: âa magic string hereâ.
But when we log some information we usually want to log it with little remark, importance level and (most important) timestamp. This information is kind of standard for logging domain. But it requires much more methods for logging API. So we need extra information to put together with objects: ⢠timestamp ⢠user message ⢠importance level (debug, info, error, etc.)
Please do not do that. This might make sense for C or Java (although it does not), but we have objects and we should filter based on those without relying on a rigid system based on random levels. Please.
⢠whatever (process hash, process name for example) ⢠sometimes it can be needed to put in log something different than object itself. (for example it can be just copy of object to not change state of log entry during app lifetime) Here is possible API based on Object extensions. It has drawbacks but it is good to think about it too:
No. This is the responsibility of the subtypes of Signal.
"it will put anObject in logs with default #info level" anObject log
"it will put anObject in logs with default #info level and given user message" anObject logWith: 'something interesting was happened with anObjectâ
"inside block we can put any logging domain information from application and also override content by specific representation" anObject logBy: [:logEntry | logEntry message: 'something interesting to be saved with our object' logEntry content: anotherObject] "here logs with interest about anObject will receive logEntry with anotherObject instead of anObjectâ
This will just favor more strings. We want to move away from them.
And similar for different kind of levels:
anObject logForDebug. anObject logForDebugWith: 'some debug message' anObject logForDebugBy: [:logEntry | ]
anObject logAsError. anObject logAsError: 'object computation was wrong' anObject logAsErrorBy: [:logEntry | ] And most general:
anObject logAs: LogLevel warn anObject logAs: LogLevel warn with: 'something interesting' anObject logAs: LogLevel warn by: [:logEntry | ]
I am definitely against this.
And in case of classic logging with strings only first expressions would be used:
'some info message' log. 'some debug message' logForDebug 'some error message' logAsError 'some warn message' logAs: LogLevel warn
Problem with this approach: it pollutes Object with 12 extra methods and it can be more. So maybe it is better to use current SystemLogger API based on class Log:
Log info: anObject Log info: anObject as: 'computation result' "as example" Log info: anObject as: [:logEntry | logEntry message: 'something interesting to be saved with our object logEntry content: anotherObject]
Log error: anObject Log error: anObject as: 'computation was wrong'' Log error: anObject as: [:logEntry | ]
Comparing to original SystemLogger versions I separate user message from object content. It makes possible to log any object with extra user message. But anyway it not feels very well IMHO. And it requires three methods for each log level. Maybe we can put this methods into LogLevel itself:
Log info add: anObject Log info add: anObject as: 'computation result' Log info add: anObject as: [:logEntry | logEntry message: 'something interesting to be saved with our object logEntry content: anotherObject]
Log error add: anObject Log error add: anObject as: 'computation was wrong'' Log error add: anObject as: [:logEntry | ]
And we can make short version for default logging level (which can be object specific):
Log add: anObject Log add: anObject as: 'computation result' Log add: anObject as: [:logEntry | ]
That's all. I hope we can produce best suitable API for object logging. Then we can think how to adopt SystemLogger or Beacon for it. Also think about this API in context that we can register specific loggers for specific objects and specific importance level.
I think this is the wrong approach and I am opposing this direction in the most constructive way I can :). Cheers, Doru
Best regards, Denis
-- www.tudorgirba.com www.feenk.com "Don't give to get. Just give."
Hi Tudor. 2016-04-26 15:36 GMT+02:00 Tudor Girba <tudor@tudorgirba.com>:
Let's think about logging API to log any object in the system. Most natural way is just send message #log to object itself:
anObject log
It would be nice replacement for Object>>logCr.
This type of usage should be discouraged in my opinion. We should instead encourage people to use typed logging signals, like we should also discourage people from using self error: âa magic string hereâ.
But when we log some information we usually want to log it with little remark, importance level and (most important) timestamp. This information is kind of standard for logging domain. But it requires much more methods for logging API. So we need extra information to put together with objects: ⢠timestamp ⢠user message ⢠importance level (debug, info, error, etc.)
Please do not do that. This might make sense for C or Java (although it does not), but we have objects and we should filter based on those without relying on a rigid system based on random levels. Please.
Before I start to think about logging I was agree with you. Now I am not. This kind of information belongs to logging domain. It can be retrieved from application objects as default values but at the end it should be explicit part of log entries. We can read it in logs for every record to realize when and why object was added to log, what this record is about. And you say let's replace this "log object context" information with first class entities "typed signals". It means that for any possible case when I want to put something in log I should create class for new signal. It's just not practical. Beacon introduce WrapperSignal to solve it. But it only provides target and timestamp. What I should do if I want to put little remark for my object? And what if I want to put little remark for ThisContextSignal? My idea that logging should be as simple as possible and we not need another "everything is signal" concept here: it is restriction. Everything is object. And every object should be able to log. And about random log levels. Their purpose is to mark log entries with importance level which is useful to explore logs. Imaging we have system which produce some events and we log them. (My and your approaches allow it. Only difference that in my approach this event will be part of log entry (as composition) and with your approach this event will be log entry itself). Now imagine that we need to explore some problem situation when particular events are appeared but they should not. I would try to find wrong places in code where events can be signalled and I would log them their. With my approach I will log them with specific importance level (#warning) and specific message to distinguish them from normal events. With my API it is super easy. With your approach I will need to create new classes to signal this situation. Also my approach allows me to configure in advance my application to put warnings in separate log. So I will not need to change app configs to simplify experiment. I will just deploy new code with extra logging and wait results in ready to use log. My proposals are not opposite to your. I just not put extra restrictions. Beacon can be based on top of it but not vice versa.
2016-04-26 17:28 GMT+02:00 Denis Kudriashov <dionisiydk@gmail.com>:
Please do not do that. This might make sense for C or Java (although it does not), but we have objects and we should filter based on those without relying on a rigid system based on random levels. Please.
And I forgot mention that my proposed API is not prevent object filtering. All information is here. So it can be implemented. And it also can be implemented by announcements. But here I just want to discuss API.
Denis, Try to look at it this way: by using objects (events, signals, announcements, whatever) and just generating them on the spot and sending them off somewhere, you have everything you need, without imposing any restrictions. If you want to use log/severity levels and/or categories and/or tags, you can do that. But I don't want to. Your objects will contain that info and you will be able to filter on it. I take a very extreme standpoint here: there should be no requirements at all. Not for the kinds of objects that one can use, nor where/how they are sent to/handled. I even do not want a specific kind of timestamp imposed. DateAndTime is way too expensive and has either too much or not enough granularity (we have no nanosecond clock). There could be some convention (a trait maybe) that says #timestamp returns a Magnitude that can be used for that purpose. If you want a small system (builder) that makes it easier to construct and signal log events, then that could be provided, but is will always be quite specific to one person's taste. Making log events subclasses of Announcement and using an Announcer instance local to a subsystem is one easy implementation choice, but not necessarily the only one. One concrete (but not perfect) implementation of my ideas can be found in the package 'Zinc-HTTP-Logging' in your image. Sven
On 26 Apr 2016, at 17:31, Denis Kudriashov <dionisiydk@gmail.com> wrote:
2016-04-26 17:28 GMT+02:00 Denis Kudriashov <dionisiydk@gmail.com>: Please do not do that. This might make sense for C or Java (although it does not), but we have objects and we should filter based on those without relying on a rigid system based on random levels. Please.
And I forgot mention that my proposed API is not prevent object filtering. All information is here. So it can be implemented. And it also can be implemented by announcements. But here I just want to discuss API.
Hi 2016-04-26 20:16 GMT+02:00 Sven Van Caekenberghe <sven@stfx.eu>:
Try to look at it this way: by using objects (events, signals, announcements, whatever) and just generating them on the spot and sending them off somewhere, you have everything you need, without imposing any restrictions.
If logging system will not allow me to log arbitrary object it would be restriction. And by "log object" I mean not just adding it to some log collection. But I need ability to mark objects with tags, messages and timestamps.
If you want to use log/severity levels and/or categories and/or tags, you can do that. But I don't want to. Your objects will contain that info and you will be able to filter on it.
Most of objects not have timestamp, tag or user message. So I can't filter them in such naked state. And instead of generating special objects with such information I want logging library take care about it. Of course for some cases I will need special objects for logs. But I should not be forced to do it every time.
Hi Denis, I was missing this fine-grained logging also so I wrote a couple of classes, long ago, that use events. It still logs to the Transcript and to a log file, in parallel. The test doesn't even make a test, to my chagrin. Look at TraceMonitor for the output bits and at senders of Object>>#etrace: aTraceEvent for the input side. It's in the class category: OCapPresentation-Base-Trace & extensions in the Cryptography repository. I was thinking remote logging, if I can ever untangle this code. It's always a question of crafty avoidance or sitting down and digging into code. I can be crafty7. Cheers, Robert On 04/26/2016 04:23 PM, Denis Kudriashov wrote:
Hi
2016-04-26 20:16 GMT+02:00 Sven Van Caekenberghe <sven@stfx.eu <mailto:sven@stfx.eu>>:
Try to look at it this way: by using objects (events, signals, announcements, whatever) and just generating them on the spot and sending them off somewhere, you have everything you need, without imposing any restrictions.
If logging system will not allow me to log arbitrary object it would be restriction. And by "log object" I mean not just adding it to some log collection. But I need ability to mark objects with tags, messages and timestamps.
If you want to use log/severity levels and/or categories and/or tags, you can do that. But I don't want to. Your objects will contain that info and you will be able to filter on it.
Most of objects not have timestamp, tag or user message. So I can't filter them in such naked state. And instead of generating special objects with such information I want logging library take care about it. Of course for some cases I will need special objects for logs. But I should not be forced to do it every time.
-- Robert . .. ... ^,^
2016-04-26 20:16 GMT+02:00 Sven Van Caekenberghe <sven@stfx.eu>:
Making log events subclasses of Announcement and using an Announcer instance local to a subsystem is one easy implementation choice, but not necessarily the only one.
One concrete (but not perfect) implementation of my ideas can be found in the package 'Zinc-HTTP-Logging' in your image.
I look at it. And I saw hierarchy of ZnClientLogEvent (9 classes) which is just data objects without any behaviour. For each class there is method in ZnClient with #log...thisEvent pattern. And most of this methods has only sender which executes real business logic on httpClient. For example: ZnConnectionEstablishedEvent ^ logConnectionEstablishedTo: url started: initialMilliseconds ^ newConnectionTo: url So for each event ZnClient has two methods. What I feel here is that if Zinc will be designed with some kind of command pattern all of this would be not needed. Instead of events and corresponding methods Zinc would have commands which implement real logic and can be logged directly without any special objects. I know designing http library is complex task. And maybe my idea is not applicable here. But what I want to say: applications usually already have objects which incapsulate all needed information for logs. And logging system should not require anything else.
On 26 Apr 2016, at 23:17, Denis Kudriashov <dionisiydk@gmail.com> wrote:
2016-04-26 20:16 GMT+02:00 Sven Van Caekenberghe <sven@stfx.eu>: Making log events subclasses of Announcement and using an Announcer instance local to a subsystem is one easy implementation choice, but not necessarily the only one.
One concrete (but not perfect) implementation of my ideas can be found in the package 'Zinc-HTTP-Logging' in your image.
I look at it.
Thanks for giving feedback.
And I saw hierarchy of ZnClientLogEvent (9 classes) which is just data objects without any behaviour.
Right now the event objects themselves are indeed pretty simple, but not totally without behaviour I would say. Most of the functionality is in the objects they encapsulate (like the request and response, the timing information).
For each class there is method in ZnClient with #log...thisEvent pattern. And most of this methods has only sender which executes real business logic on httpClient. For example:
ZnConnectionEstablishedEvent ^ logConnectionEstablishedTo: url started: initialMilliseconds ^ newConnectionTo: url
So for each event ZnClient has two methods.
The fact that the logging is abstracted into helper methods is not a requirement per se, it is just code organisation, preferable to super long methods. I see only one #logXXX method per log event.
What I feel here is that if Zinc will be designed with some kind of command pattern all of this would be not needed. Instead of events and corresponding methods Zinc would have commands which implement real logic and can be logged directly without any special objects.
I know designing http library is complex task. And maybe my idea is not applicable here.
The idea of using command objects as log objects might work in specific situations, it is a good idea, but I doubt it would be applicable to many situations, or cover all logging needs. I'll certainly think about it.
But what I want to say: applications usually already have objects which incapsulate all needed information for logs. And logging system should not require anything else.
But that is what is happening here (where it is applicable): the log event object that signals that a request resulted in a specific response for example, contains the actual, original objects; that is why doing this is cheap, the objects already exist. Sven
Denis,
Am 26.04.2016 um 17:28 schrieb Denis Kudriashov <dionisiydk@gmail.com>:
Hi Tudor.
2016-04-26 15:36 GMT+02:00 Tudor Girba <tudor@tudorgirba.com <mailto:tudor@tudorgirba.com>>:
Let's think about logging API to log any object in the system. Most natural way is just send message #log to object itself:
anObject log
It would be nice replacement for Object>>logCr.
This type of usage should be discouraged in my opinion. We should instead encourage people to use typed logging signals, like we should also discourage people from using self error: âa magic string hereâ.
But when we log some information we usually want to log it with little remark, importance level and (most important) timestamp. This information is kind of standard for logging domain. But it requires much more methods for logging API. So we need extra information to put together with objects: ⢠timestamp ⢠user message ⢠importance level (debug, info, error, etc.)
Please do not do that. This might make sense for C or Java (although it does not), but we have objects and we should filter based on those without relying on a rigid system based on random levels. Please.
Before I start to think about logging I was agree with you. Now I am not. This kind of information belongs to logging domain. It can be retrieved from application objects as default values but at the end it should be explicit part of log entries. We can read it in logs for every record to realize when and why object was added to log, what this record is about.
And you say let's replace this "log object context" information with first class entities "typed signals". It means that for any possible case when I want to put something in log I should create class for new signal. It's just not practical. Beacon introduce WrapperSignal to solve it. But it only provides target and timestamp. What I should do if I want to put little remark for my object? And what if I want to put little remark for ThisContextSignal?
My idea that logging should be as simple as possible and we not need another "everything is signal" concept here: it is restriction. Everything is object. And every object should be able to log.
And about random log levels. Their purpose is to mark log entries with importance level which is useful to explore logs. Imaging we have system which produce some events and we log them. (My and your approaches allow it. Only difference that in my approach this event will be part of log entry (as composition) and with your approach this event will be log entry itself). Now imagine that we need to explore some problem situation when particular events are appeared but they should not. I would try to find wrong places in code where events can be signalled and I would log them their. With my approach I will log them with specific importance level (#warning) and specific message to distinguish them from normal events. With my API it is super easy. With your approach I will need to create new classes to signal this situation. Also my approach allows me to configure in advance my application to put warnings in separate log. So I will not need to change app configs to simplify experiment. I will just deploy new code with extra logging and wait results in ready to use log.
My proposals are not opposite to your. I just not put extra restrictions. Beacon can be based on top of it but not vice versa.
I must confess I cannot follow you completely. What we were/are talking about is that the assumption a logging entry needs timestamp, log level and such is not appropriate. If you have legacy syslog style logging in mind it appears natural but for a lot of use cases it is not. Even if you could say that a timestamp is part of the logging domain it is not said if that timestamp needs to be part of the log object or the logger consuming this object. This question arises for every quality of a logging object. Even the logging level could be some behavioral quality that a logger matches to log levels. Contrary to this is logging thisContext which has to be done in the log object. I think the hard part is the way of distribution of log objects and filtering of them. While the former is being discussed with Beacon the latter is mostly ignored while being really important. Not having default qualities of a log object is good on one hand but on the other hand the filtering is much harder. In SystemLogger we didn't go far enough at first. The Log class contained level and such. That was the reason for me to split it into BasicLog consisting of timestamp and a message object and Log which contains the extra qualities. Nowadays I think you should be able to use any object as log object. The provided classes are just helpers. A composed object that has timestamp, level and a message object is a good utility but not a requirement. We need to support all of these. And so I would object against putting a lot of protocol in the Object class. In SystemLogger you have Object>>#asLog ^ self class newLog message: self Object class>>#newLog ^ self logClass new Object class>>#logClass "Hook supporting the redefinition by object of their associated log. When using myObject asLog emit, the logClass will be used and myObject will be passed as message argument." ^ Log So assuming the Log class would not contain log levels but SysLog would do you could easily override #logClass in your domain object and use it this way MyDomainClass class>>#logClass ^ SysLog myDomainObject asLog warning; emit This way we do not need to pollute Object with a lot of methods that are tight to one use case. The call to #warning could be something else that only depends on the Log class you want to use. So to me the discussion about Log classes is not very helpful. We can have dedicated log classes like the stack capturing one but also one that is composed of the message object and certain qualities. If you would have a WrappedSyslogSignal you can have a log object that is composed and syslog aware by providing log levels. Again I think the hard part is to have flexible logging and still be able to filter it. I would like to be able to attach a handful of loggers and be sure the loggers get the right set of log objects they are interested in. Norbert
Hi Norbert 2016-04-27 10:43 GMT+02:00 Norbert Hartl <norbert@hartl.name>:
So assuming the Log class would not contain log levels but SysLog would do you could easily override #logClass in your domain object and use it this way
MyDomainClass class>>#logClass ^ SysLog
myDomainObject asLog warning; emit
This way we do not need to pollute Object with a lot of methods that are tight to one use case. The call to #warning could be something else that only depends on the Log class you want to use.
There is one problem with this approach when we split preparation and emitting of log object. It will always produce garbage. If no logs will have interest in myDomainObject or #warning-level messages application will continue create log entries. I think it is important to minimize cost of logging when nobody have interest on particular event. If debug-level log is disabled then no garbage should be created. If stack traces log is disabled then no stack information should be retrieved anywhere. To achieve this we should create log entry instances only when we will find any logs for them. It imposes restriction on possible API. At point when we are ready to log something we should have all information which can be part of filter. So if we want to filter logs by domain objects and log-levels we need both parameters in one message send. Then we can ask every registered log for interest about both of them. And only when we will find any one we will create log entry instance for them.
Le 27/4/16 à 13:01, Denis Kudriashov a écrit :
Hi Norbert
2016-04-27 10:43 GMT+02:00 Norbert Hartl <norbert@hartl.name <mailto:norbert@hartl.name>>:
So assuming the Log class would not contain log levels but SysLog would do you could easily override #logClass in your domain object and use it this way
MyDomainClass class>>#logClass ^ SysLog
myDomainObject asLog warning; emit
This way we do not need to pollute Object with a lot of methods that are tight to one use case. The call to #warning could be something else that only depends on the Log class you want to use.
There is one problem with this approach when we split preparation and emitting of log object. It will always produce garbage. If no logs will have interest in myDomainObject or #warning-level messages application will continue create log entries. Denis I do not get what you mean with the sentence above.
I think it is important to minimize cost of logging when nobody have interest on particular event. If debug-level log is disabled then no garbage should be created. If stack traces log is disabled then no stack information should be retrieved anywhere. To achieve this we should create log entry instances only when we will find any logs for them. It imposes restriction on possible API. At point when we are ready to log something we should have all information which can be part of filter. So if we want to filter logs by domain objects and log-levels we need both parameters in one message send. Then we can ask every registered log for interest about both of them. And only when we will find any one we will create log entry instance for them.
2016-04-27 21:11 GMT+02:00 stepharo <stepharo@free.fr>:
There is one problem with this approach when we split preparation and emitting of log object. It will always produce garbage. If no logs will have interest in myDomainObject or #warning-level messages application will continue create log entries.
Denis I do not get what you mean with the sentence above.
With SystemLogger we would write: anObject asLog emit. And your code will always create Log instance which would be useless garbage when nobody interested in it (not logs want it). Same with Beacon: anObject asBeaconSignal log. And especially it is problem when we log thisContext: ContextStackSignal log It will always extract full stack information although not logs will record it. I think it is important to address this issue: logging code should be not expensive when nobody use logs.
2016-04-27 10:43 GMT+02:00 Norbert Hartl <norbert@hartl.name>:
I must confess I cannot follow you completely. What we were/are talking about is that the assumption a logging entry needs timestamp, log level and such is not appropriate. If you have legacy syslog style logging in mind it appears natural but for a lot of use cases it is not.
Could you provide example where it is not?
Even if you could say that a timestamp is part of the logging domain it is not said if that timestamp needs to be part of the log object or the logger consuming this object. This question arises for every quality of a logging object. Even the logging level could be some behavioral quality that a logger matches to log levels. Contrary to this is logging thisContext which has to be done in the log object. I think the hard part is the way of distribution of log objects and filtering of them. While the former is being discussed with Beacon the latter is mostly ignored while being really important. Not having default qualities of a log object is good on one hand but on the other hand the filtering is much harder. In SystemLogger we didn't go far enough at first. The Log class contained level and such. That was the reason for me to split it into BasicLog consisting of timestamp and a message object and Log which contains the extra qualities.
My problem with such approach is that it forces me to create hierarchy of log events as subclasses of base log component. Imaging that my application already provide hierarchy of events but they have no timestamps. How to log them? Should I use some WrapperSignal? Now imaging that application uses some library which provides events too. But this events are log entries themselves. What I will see in my logs? I will see mix of WrapperSignal's and normal events. It would be not easy to analize such log. That's why I want unified log entries. I would model it with single class LogEntry which nobody needs to subclass. It would contain logging domain information: timestamp, importance level, user message and whatever. And it would have *content *property to keep logging object. So our tools can rely on this structure to make it easy to work with logs. And when anybody will look at particular log he will be sure that logging object is inside "content" variables of each record
2016-04-27 14:16 GMT+02:00 Denis Kudriashov <dionisiydk@gmail.com>:
My problem with such approach is that it forces me to create hierarchy of log events as subclasses of base log component. Imaging that my application already provide hierarchy of events but they have no timestamps. How to log them? Should I use some WrapperSignal? Now imaging that application uses some library which provides events too. But this events are log entries themselves. What I will see in my logs? I will see mix of WrapperSignal's and normal events. It would be not easy to analize such log.
And also it makes difficult to filter such logs. For library events I can use announcements approach directly (for example). But for application events it would not work because they are inside wrappers
I'd like to mention my TraceEvent and TraceMonitor classes, again, as it supports most of what you guys are talking about. I believe I have resolved my package naming, so you can find these classes in the SqueakSource's Cryptography repository in the OCapPresents package. TraceEvent is a single loggable event class with timestamp ivar, generic msg ivar, filterable domain ivar, remote ivar. These ivars are converted to strings during logEvent handling in the monitor, so the msg ivar can hold a user-defined loggable event objects that convert to a preferred string. There would be no need to write separate wrappers for each use. The monitor can have various domains enabled or disabled: use TraceMonitor>>#enableDomain:/#disableDomain: with a symbol. My use has a bunch of convenience methods for my domain use, but a new domain can be added and one can use the #etrace:msg: variety, which accepts the domain as the first parameter and the domain specific msg object as the second parameter. The monitor can write to multiple trace streams. I am missing logLevel, though I tried to add severity but it is non-functional. It would be easy enough to add. I do not know if this aligns with the Announcements solution you all are talking about or if it meets all your needs. It is sounding like it meets most of the logging domain information, it is filterable, has multiple output streams, uses the event system so it is lightly couple to the domain. Whatever solution is arrived at, I hope it is a shared infrastructure service in squeak as well, along with Fuel, then I would likely switch to using the standard. On 04/27/2016 08:16 AM, Denis Kudriashov wrote:
2016-04-27 10:43 GMT+02:00 Norbert Hartl <norbert@hartl.name <mailto:norbert@hartl.name>>:
I must confess I cannot follow you completely. What we were/are talking about is that the assumption a logging entry needs timestamp, log level and such is not appropriate. If you have legacy syslog style logging in mind it appears natural but for a lot of use cases it is not.
Could you provide example where it is not?
Even if you could say that a timestamp is part of the logging domain it is not said if that timestamp needs to be part of the log object or the logger consuming this object. This question arises for every quality of a logging object. Even the logging level could be some behavioral quality that a logger matches to log levels. Contrary to this is logging thisContext which has to be done in the log object. I think the hard part is the way of distribution of log objects and filtering of them. While the former is being discussed with Beacon the latter is mostly ignored while being really important. Not having default qualities of a log object is good on one hand but on the other hand the filtering is much harder. In SystemLogger we didn't go far enough at first. The Log class contained level and such. That was the reason for me to split it into BasicLog consisting of timestamp and a message object and Log which contains the extra qualities.
My problem with such approach is that it forces me to create hierarchy of log events as subclasses of base log component. Imaging that my application already provide hierarchy of events but they have no timestamps. How to log them? Should I use some WrapperSignal? Now imaging that application uses some library which provides events too. But this events are log entries themselves. What I will see in my logs? I will see mix of WrapperSignal's and normal events. It would be not easy to analize such log.
That's why I want unified log entries. I would model it with single class LogEntry which nobody needs to subclass. It would contain logging domain information: timestamp, importance level, user message and whatever. And it would have *content *property to keep logging object. So our tools can rely on this structure to make it easy to work with logs. And when anybody will look at particular log he will be sure that logging object is inside "content" variables of each record
-- Robert . .. ... ^,^
Le 27/4/16 à 14:16, Denis Kudriashov a écrit :
2016-04-27 10:43 GMT+02:00 Norbert Hartl <norbert@hartl.name <mailto:norbert@hartl.name>>:
I must confess I cannot follow you completely. What we were/are talking about is that the assumption a logging entry needs timestamp, log level and such is not appropriate. If you have legacy syslog style logging in mind it appears natural but for a lot of use cases it is not.
Could you provide example where it is not?
Even if you could say that a timestamp is part of the logging domain it is not said if that timestamp needs to be part of the log object or the logger consuming this object. This question arises for every quality of a logging object. Even the logging level could be some behavioral quality that a logger matches to log levels. Contrary to this is logging thisContext which has to be done in the log object. I think the hard part is the way of distribution of log objects and filtering of them. While the former is being discussed with Beacon the latter is mostly ignored while being really important. Not having default qualities of a log object is good on one hand but on the other hand the filtering is much harder. In SystemLogger we didn't go far enough at first. The Log class contained level and such. That was the reason for me to split it into BasicLog consisting of timestamp and a message object and Log which contains the extra qualities.
My problem with such approach is that it forces me to create hierarchy of log events as subclasses of base log component.
not necessary we could have Log being a potential wrapper.
Imaging that my application already provide hierarchy of events but they have no timestamps. How to log them? Should I use some WrapperSignal? Now imaging that application uses some library which provides events too. But this events are log entries themselves. What I will see in my logs? I will see mix of WrapperSignal's and normal events. It would be not easy to analize such log.
That's why I want unified log entries. I would model it with single class LogEntry which nobody needs to subclass. It would contain logging domain information: timestamp, importance level, user message and whatever. And it would have *content *property to keep logging object. So our tools can rely on this structure to make it easy to work with logs. And when anybody will look at particular log he will be sure that logging object is inside "content" variables of each record
2016-04-27 21:12 GMT+02:00 stepharo <stepharo@free.fr>:
extra qualities.
My problem with such approach is that it forces me to create hierarchy of log events as subclasses of base log component.
not necessary we could have Log being a potential wrapper.
But what about my example below?
Imaging that my application already provide hierarchy of events but they have no timestamps. How to log them? Should I use some WrapperSignal? Now imaging that application uses some library which provides events too. But this events are log entries themselves. What I will see in my logs? I will see mix of WrapperSignal's and normal events. It would be not easy to analize such log.
Do you think it is not problem?
That's why I want unified log entries. I would model it with single class LogEntry which nobody needs to subclass. It would contain logging domain information: timestamp, importance level, user message and whatever. And it would have *content *property to keep logging object. So our tools can rely on this structure to make it easy to work with logs. And when anybody will look at particular log he will be sure that logging object is inside "content" variables of each record
Hi Denis,
On Apr 27, 2016, at 2:16 PM, Denis Kudriashov <dionisiydk@gmail.com> wrote:
2016-04-27 10:43 GMT+02:00 Norbert Hartl <norbert@hartl.name>: I must confess I cannot follow you completely. What we were/are talking about is that the assumption a logging entry needs timestamp, log level and such is not appropriate. If you have legacy syslog style logging in mind it appears natural but for a lot of use cases it is not.
Could you provide example where it is not?
I just did a project in which I needed to understand a real-time parallel system that had 3 layers of abstractions. The code already had in place a log system based on log levels. If I opened the #debug level, I would get a ton of information, even though I wanted to focus on exactly one layer, or sometimes only one a certain type of leg entries. This is a common place scenario and it is time we can pick events based on their nature. The numbered layers come from languages where false=0, so letâs not use that as the standard we want to build on :).
Even if you could say that a timestamp is part of the logging domain it is not said if that timestamp needs to be part of the log object or the logger consuming this object. This question arises for every quality of a logging object. Even the logging level could be some behavioral quality that a logger matches to log levels. Contrary to this is logging thisContext which has to be done in the log object. I think the hard part is the way of distribution of log objects and filtering of them. While the former is being discussed with Beacon the latter is mostly ignored while being really important. Not having default qualities of a log object is good on one hand but on the other hand the filtering is much harder. In SystemLogger we didn't go far enough at first. The Log class contained level and such. That was the reason for me to split it into BasicLog consisting of timestamp and a message object and Log which contains the extra qualities.
My problem with such approach is that it forces me to create hierarchy of log events as subclasses of base log component.
But, you do not have to. Only if you want to distinguish between different log signals based on types. It is exactly the same type of problem that you have when you design the Exceptions in your system, or the domain-level Announcements in your system. Do you want to have fine grained types or use one single generic Exception? Do you want to have fine-grained or use plain Announcements? You can do it both ways, but it turns out you understand your system better if you use the types. Nevertheless, for prototyping purposes, you can certainly use quick logging.
Imaging that my application already provide hierarchy of events but they have no timestamps. How to log them? Should I use some WrapperSignal? Now imaging that application uses some library which provides events too. But this events are log entries themselves. What I will see in my logs? I will see mix of WrapperSignal's and normal events. It would be not easy to analize such log. That's why I want unified log entries. I would model it with single class LogEntry which nobody needs to subclass. It would contain logging domain information: timestamp, importance level, user message and whatever. And it would have content property to keep logging object. So our tools can rely on this structure to make it easy to work with logs. And when anybody will look at particular log he will be sure that logging object is inside "content" variables of each record
Signals are announcements. If you will have some events, those should be announcements. We could add to Announcements the ability to decorate an Announcement object (or at least a Signal one), we can tackle your scenario in a different way. Announcements is the unifying platform, not the logging. Logging is just an application of Announcements. But, the other point of view is that we should work to add instance variable filtering to Announcements, ideally in a way that does not pose performance penalty when you filter only by class. Once we do that we can have any combination you want. Also, just because you use Announcements does not put any limitation on the concrete domain objects you want to log. In any logging system you will have some wrapping object that will hold the concrete object. An Announcement is a great wrapping object exactly because it comes with the mechanism of transportation throughout the image, which is a technical prerequisite for logging anyway. Cheers, Doru -- www.tudorgirba.com www.feenk.com "Don't give to get. Just give."
Hi,
On Apr 27, 2016, at 10:43 AM, Norbert Hartl <norbert@hartl.name> wrote:
Denis,
Am 26.04.2016 um 17:28 schrieb Denis Kudriashov <dionisiydk@gmail.com>:
Hi Tudor.
2016-04-26 15:36 GMT+02:00 Tudor Girba <tudor@tudorgirba.com>:
Let's think about logging API to log any object in the system. Most natural way is just send message #log to object itself:
anObject log
It would be nice replacement for Object>>logCr.
This type of usage should be discouraged in my opinion. We should instead encourage people to use typed logging signals, like we should also discourage people from using self error: âa magic string hereâ.
But when we log some information we usually want to log it with little remark, importance level and (most important) timestamp. This information is kind of standard for logging domain. But it requires much more methods for logging API. So we need extra information to put together with objects: ⢠timestamp ⢠user message ⢠importance level (debug, info, error, etc.)
Please do not do that. This might make sense for C or Java (although it does not), but we have objects and we should filter based on those without relying on a rigid system based on random levels. Please.
Before I start to think about logging I was agree with you. Now I am not. This kind of information belongs to logging domain. It can be retrieved from application objects as default values but at the end it should be explicit part of log entries. We can read it in logs for every record to realize when and why object was added to log, what this record is about.
And you say let's replace this "log object context" information with first class entities "typed signals". It means that for any possible case when I want to put something in log I should create class for new signal. It's just not practical. Beacon introduce WrapperSignal to solve it. But it only provides target and timestamp. What I should do if I want to put little remark for my object? And what if I want to put little remark for ThisContextSignal?
My idea that logging should be as simple as possible and we not need another "everything is signal" concept here: it is restriction. Everything is object. And every object should be able to log.
And about random log levels. Their purpose is to mark log entries with importance level which is useful to explore logs. Imaging we have system which produce some events and we log them. (My and your approaches allow it. Only difference that in my approach this event will be part of log entry (as composition) and with your approach this event will be log entry itself). Now imagine that we need to explore some problem situation when particular events are appeared but they should not. I would try to find wrong places in code where events can be signalled and I would log them their. With my approach I will log them with specific importance level (#warning) and specific message to distinguish them from normal events. With my API it is super easy. With your approach I will need to create new classes to signal this situation. Also my approach allows me to configure in advance my application to put warnings in separate log. So I will not need to change app configs to simplify experiment. I will just deploy new code with extra logging and wait results in ready to use log.
My proposals are not opposite to your. I just not put extra restrictions. Beacon can be based on top of it but not vice versa.
I must confess I cannot follow you completely. What we were/are talking about is that the assumption a logging entry needs timestamp, log level and such is not appropriate. If you have legacy syslog style logging in mind it appears natural but for a lot of use cases it is not.
Yes.
Even if you could say that a timestamp is part of the logging domain it is not said if that timestamp needs to be part of the log object or the logger consuming this object.
This is a good point. I still see it closer to the event than to the logger.
This question arises for every quality of a logging object. Even the logging level could be some behavioral quality that a logger matches to log levels. Contrary to this is logging thisContext which has to be done in the log object.
Yes. I think it would be worthwhile to think about a composition mechanism. We could potentially use decorators for capturing extra information in the log event object.
I think the hard part is the way of distribution of log objects and filtering of them. While the former is being discussed with Beacon the latter is mostly ignored while being really important. Not having default qualities of a log object is good on one hand but on the other hand the filtering is much harder.
I agree that we would benefit from an instance-based filtering mechanism, but I do not see why this is harder in Announcement. However we do it, it can be added to Announcements and it is available for all purposes (not just logging). Maybe I am missing something.
In SystemLogger we didn't go far enough at first. The Log class contained level and such. That was the reason for me to split it into BasicLog consisting of timestamp and a message object and Log which contains the extra qualities. Nowadays I think you should be able to use any object as log object. The provided classes are just helpers. A composed object that has timestamp, level and a message object is a good utility but not a requirement. We need to support all of these. And so I would object against putting a lot of protocol in the Object class. In SystemLogger you have
Object>>#asLog ^ self class newLog message: self
One thing that I think is misleading (I remember it took me some minutes to wrap my head around it) is the way SystemLogger uses the term âlogâ. In English, log denotes all entries (a log book), but in SystemLogger it is used to denote one event. In any case, having an as* pattern (like it exists in Beacon) is the way to go.
Object class>>#newLog ^ self logClass new
Object class>>#logClass "Hook supporting the redefinition by object of their associated log. When using myObject asLog emit, the logClass will be used and myObject will be passed as message argument."
^ Log
This is another thing that is different from Beacon. I see the logging as a description of an event that is worthwhile capturing. This event has a strategy to record things. For example, when you capture an exception you might want to capture the complete context including the sender objects, or just the methods from the stack. This decision is tied to the Exception, but depends on the logging place. That is why I think we should not invest much in the pattern of hardcoding the strategy with the object. So, from this point of view, I would not want to pursue #logClass.
So assuming the Log class would not contain log levels but SysLog would do you could easily override #logClass in your domain object and use it this way
MyDomainClass class>>#logClass ^ SysLog
myDomainObject asLog warning; emit
This way we do not need to pollute Object with a lot of methods that are tight to one use case. The call to #warning could be something else that only depends on the Log class you want to use.
Yes.
So to me the discussion about Log classes is not very helpful. We can have dedicated log classes like the stack capturing one but also one that is composed of the message object and certain qualities. If you would have a WrappedSyslogSignal you can have a log object that is composed and syslog aware by providing log levels.
I would actually like to invest in building a composition mechanism. This would allow us to compose logging objects with the information we would like to have.
Again I think the hard part is to have flexible logging and still be able to filter it. I would like to be able to attach a handful of loggers and be sure the loggers get the right set of log objects they are interested in.
Do you have a concrete set of examples that you would like to see working? I think it would be useful to have a set of these concrete use cases to catch different design decisions against them. I have some cases and I will try to summarize them, but after the release of Pharo. Cheers, Doru
Norbert
-- www.tudorgirba.com www.feenk.com "If you can't say why something is relevant, it probably isn't."
I must confess I cannot follow you completely. What we were/are talking about is that the assumption a logging entry needs timestamp, log level and such is not appropriate. If you have legacy syslog style logging in mind it appears natural but for a lot of use cases it is not. Even if you could say that a timestamp is part of the logging domain it is not said if that timestamp needs to be part of the log object or the logger consuming this object. This question arises for every quality of a logging object. Even the logging level could be some behavioral quality that a logger matches to log levels. Contrary to this is logging thisContext which has to be done in the log object. I think the hard part is the way of distribution of log objects and filtering of them. While the former is being discussed with Beacon the latter is mostly ignored while being really important. Not having default qualities of a log object is good on one hand but on the other hand the filtering is much harder. In SystemLogger we didn't go far enough at first. The Log class contained level and such. That was the reason for me to split it into BasicLog consisting of timestamp and a message object and Log which contains the extra qualities. Nowadays I think you should be able to use any object as log object. The provided classes are just helpers. A composed object that has timestamp, level and a message object is a good utility but not a requirement. We need to support all of these. And so I would object against putting a lot of protocol in the Object class. In SystemLogger you have
Object>>#asLog ^ self class newLog message: self
Object class>>#newLog ^ self logClass new
Object class>>#logClass "Hook supporting the redefinition by object of their associated log. When using myObject asLog emit, the logClass will be used and myObject will be passed as message argument."
^ Log
So assuming the Log class would not contain log levels but SysLog would do you could easily override #logClass in your domain object and use it this way
MyDomainClass class>>#logClass ^ SysLog
myDomainObject asLog warning; emit
This way we do not need to pollute Object with a lot of methods that are tight to one use case. The call to #warning could be something else that only depends on the Log class you want to use.
So to me the discussion about Log classes is not very helpful. We can have dedicated log classes like the stack capturing one but also one that is composed of the message object and certain qualities. If you would have a WrappedSyslogSignal you can have a log object that is composed and syslog aware by providing log levels. Again I think the hard part is to have flexible logging and still be able to filter it. I would like to be able to attach a handful of loggers and be sure the loggers get the right set of log objects they are interested in.
Hi norbert I agree. I have the impression that in SystemLogger I would change message: into object: in Log and remove all the extension API I tried to design. This way people can just pass the object they want if they want still to have the object wrapped into a Log instances. I think that Log instances and subclasses would be nice to have specific behavior (like menu actions when we want to manipulate logs). For example, I would like to have a tool looging all the methods that I did not define during a prototype session and after I can click on them and say "define skeleton" and boum I get a skeleton for all the methods inside their respective classes. Stef
This type of usage should be discouraged in my opinion. We should instead encourage people to use typed logging signals, like we should also discourage people from using self error: âa magic string hereâ.
> But when we log some information we usually want to log it with little remark, importance level and (most important) timestamp. This information is kind of standard for logging domain. But it requires much more methods for logging API. > So we need extra information to put together with objects: > ⢠timestamp > ⢠user message > ⢠importance level (debug, info, error, etc.)
Please do not do that. This might make sense for C or Java (although it does not), but we have objects and we should filter based on those without relying on a rigid system based on random levels. Please.
Before I start to think about logging I was agree with you. Now I am not. This kind of information belongs to logging domain. It can be retrieved from application objects as default values but at the end it should be explicit part of log entries. We can read it in logs for every record to realize when and why object was added to log, what this record is about.
But denis why this is not for a certain kind of subclass You have Log with the minimal information (timestamp and an object) then you can have logger with levels and other.
And you say let's replace this "log object context" information with first class entities "typed signals". It means that for any possible case when I want to put something in log I should create class for new signal. It's just not practical.
why? MySpecialLog ... emit
Beacon introduce WrapperSignal to solve it. But it only provides target and timestamp. What I should do if I want to put little remark for my object? And what if I want to put little remark for ThisContextSignal?
My idea that logging should be as simple as possible and we not need another "everything is signal" concept here: it is restriction. Everything is object. And every object should be able to log.
In the minimalLog MinimalLog object: MyCoolObject new; emit no need of message
And about random log levels. Their purpose is to mark log entries with importance level which is useful to explore logs. Imaging we have system which produce some events and we log them. (My and your approaches allow it. Only difference that in my approach this event will be part of log entry (as composition) and with your approach this event will be log entry itself). Now imagine that we need to explore some problem situation when particular events are appeared but they should not. I would try to find wrong places in code where events can be signalled and I would log them their. With my approach I will log them with specific importance level (#warning) and specific message to distinguish them from normal events. With my API it is super easy. With your approach I will need to create new classes to signal this situation. Also my approach allows me to configure in advance my application to put warnings in separate log. So I will not need to change app configs to simplify experiment. I will just deploy new code with extra logging and wait results in ready to use log.
My proposals are not opposite to your. I just not put extra restrictions. Beacon can be based on top of it but not vice versa.
2016-04-27 20:50 GMT+02:00 stepharo <stepharo@free.fr>:
And you say let's replace this "log object context" information with first class entities "typed signals". It means that for any possible case when I want to put something in log I should create class for new signal. It's just not practical.
why? MySpecialLog ... emit
What I am talking about is that I don't want create MySpecialLog for any MySpecialDomainObject which I want to log.
2016-04-28 10:13 GMT+02:00 Denis Kudriashov <dionisiydk@gmail.com>:
2016-04-27 20:50 GMT+02:00 stepharo <stepharo@free.fr>:
And you say let's replace this "log object context" information with first class entities "typed signals". It means that for any possible case when I want to put something in log I should create class for new signal. It's just not practical.
why? MySpecialLog ... emit
What I am talking about is that I don't want create MySpecialLog for any MySpecialDomainObject which I want to log.
Traits? Put you logging api in a Trait instead of Object and let your MySpecialDomainObject use this trait ?
2016-04-28 10:20 GMT+02:00 Nicolai Hess <nicolaihess@gmail.com>:
What I am talking about is that I don't want create MySpecialLog for any
MySpecialDomainObject which I want to log.
Traits?
Put you logging api in a Trait instead of Object and let your MySpecialDomainObject use this trait ?
Really? Try remember usual workflow when we investigate some problems with code when we can't use debugger. We put kind of "Transcript show:" in multiple places to see state of our objects at concrete point of time. With object logging we will log our objects directly without converting to strings. Do you want to stop your "debugging workflow" every time you need to log objects which not support it? (to add special trait). But anyway with Trait you can't add timestamp to your domain object which is always required for logs (I think we all agree about timestamp).
Hi,
On Apr 28, 2016, at 10:55 AM, Denis Kudriashov <dionisiydk@gmail.com> wrote:
2016-04-28 10:20 GMT+02:00 Nicolai Hess <nicolaihess@gmail.com>: What I am talking about is that I don't want create MySpecialLog for any MySpecialDomainObject which I want to log.
Traits?
Put you logging api in a Trait instead of Object and let your MySpecialDomainObject use this trait ?
Really? Try remember usual workflow when we investigate some problems with code when we can't use debugger. We put kind of "Transcript show:" in multiple places to see state of our objects at concrete point of time. With object logging we will log our objects directly without converting to strings. Do you want to stop your "debugging workflow" every time you need to log objects which not support it? (to add special trait).
This is a totally different scenario than the one of logging for an unforeseen situation. For this purpose, in Beacon we have dedicated signals such as those that capture the stack or the context and we can imagine several more. It is more powerful than Transcript and requires no string. Furthermore, because we have the type signal, we can also easily have an inspector that shows the relevant information.
But anyway with Trait you can't add timestamp to your domain object which is always required for logs (I think we all agree about timestamp).
We can indeed agree on timestamp, but as Sven said, we might need flexibility on how to capture it (DateAndTime vs ZTimestamp). Cheers, Doru -- www.tudorgirba.com www.feenk.com "What is more important: To be happy, or to make happy?"
2016-04-28 11:07 GMT+02:00 Tudor Girba <tudor@tudorgirba.com>:
Put you logging api in a Trait instead of Object and let your MySpecialDomainObject use this trait ?
Really? Try remember usual workflow when we investigate some problems with code when we can't use debugger. We put kind of "Transcript show:" in multiple places to see state of our objects at concrete point of time. With object logging we will log our objects directly without converting to strings. Do you want to stop your "debugging workflow" every time you need to log objects which not support it? (to add special trait).
This is a totally different scenario than the one of logging for an unforeseen situation. For this purpose, in Beacon we have dedicated signals such as those that capture the stack or the context and we can imagine several more. It is more powerful than Transcript and requires no string. Furthermore, because we have the type signal, we can also easily have an inspector that shows the relevant information.
I hope you not think that I suggested to log strings. I never did it. I proposed to log domain objects instead of signals with ability to annotate them with additional information.
Hi,
On Apr 28, 2016, at 2:29 PM, Denis Kudriashov <dionisiydk@gmail.com> wrote:
2016-04-28 11:07 GMT+02:00 Tudor Girba <tudor@tudorgirba.com>:
Put you logging api in a Trait instead of Object and let your MySpecialDomainObject use this trait ?
Really? Try remember usual workflow when we investigate some problems with code when we can't use debugger. We put kind of "Transcript show:" in multiple places to see state of our objects at concrete point of time. With object logging we will log our objects directly without converting to strings. Do you want to stop your "debugging workflow" every time you need to log objects which not support it? (to add special trait).
This is a totally different scenario than the one of logging for an unforeseen situation. For this purpose, in Beacon we have dedicated signals such as those that capture the stack or the context and we can imagine several more. It is more powerful than Transcript and requires no string. Furthermore, because we have the type signal, we can also easily have an inspector that shows the relevant information.
I hope you not think that I suggested to log strings. I never did it. I proposed to log domain objects instead of signals with ability to annotate them with additional information.
No, I did not suggest that you want to log strings. I simply said that this type of use case is different than the regular logging use case. I think it is important to treat these two separately because indeed when you debug you are in a prototyping mode and you want to go fast. In this situation, you do not want to have to create a separate class. But, for the long term logging you have different requirements and there you want to be more rigorous, and in that scenario creating a new class is acceptable. If we design a logging infrastructure the second use case is what we want to optimize around. Of course, we should still think about the prototyping part. I found that it is often more interesting to log entire contexts (and have a post-mortem debugger) than individual objects. Nevertheless, with something as simple as: object asBeaconSignal log. It worked fine. And if I really wanted to add extra information, I rudimentary did: {âsome textâ . object } asBeaconSignal log. Or even: {âsome textâ . #someSymbol . 42 . object } asBeaconSignal log. It is not the most elegant solution, but it is very malleable and good enough for debugging purposes. If we would have instance-based filtering for announcements, we could filter based on that without any extra effort. Also, if we would have a composition mechanism in place, we could build these objects with a more elegant API. Regarding your statement of logging domain objects, you will have to store these objects with the additional information somewhere, and that will be a wrapper class. I do not see the difference with the Signal. Cheers, Doru -- www.tudorgirba.com www.feenk.com "We can create beautiful models in a vacuum. But, to get them effective we have to deal with the inconvenience of reality."
2016-04-28 14:51 GMT+02:00 Tudor Girba <tudor@tudorgirba.com>:
And if I really wanted to add extra information, I rudimentary did:
{âsome textâ . object } asBeaconSignal log.
Or even:
{âsome textâ . #someSymbol . 42 . object } asBeaconSignal log.
And for such cases we definitely need simple #log message without #asBeaconSignal. It can be hidden inside. Or it can be: Log add: {âsome textâ . #someSymbol . 42 . object }
Le 28/4/16 à 15:06, Denis Kudriashov a écrit :
2016-04-28 14:51 GMT+02:00 Tudor Girba <tudor@tudorgirba.com <mailto:tudor@tudorgirba.com>>:
And if I really wanted to add extra information, I rudimentary did:
{âsome textâ . object } asBeaconSignal log.
Or even:
{âsome textâ . #someSymbol . 42 . object } asBeaconSignal log.
And for such cases we definitely need simple #log message without #asBeaconSignal. It can be hidden inside. Or it can be:
Log add: {âsome textâ . #someSymbol . 42 . object }
Yes I would prefer that instead sending add: Log information: {âsome textâ . #someSymbol . 42 . object }
2016-04-28 14:51 GMT+02:00 Tudor Girba <tudor@tudorgirba.com>:
It is not the most elegant solution, but it is very malleable and good enough for debugging purposes. If we would have instance-based filtering for announcements, we could filter based on that without any extra effort. Also, if we would have a composition mechanism in place, we could build these objects with a more elegant API.
Regarding your statement of logging domain objects, you will have to store these objects with the additional information somewhere, and that will be a wrapper class. I do not see the difference with the Signal.
Difference with Beacon is that users will not depends on objects from logging library. Nobody needs to subclass core components like Signal. Instead domain objects will be added to logs inside general LogEntry instances which will be hidden from user and only available inside logs. And LogEntry will allow include additional information to itself by appropriate logging API. Question is: does it better? And this is what problem I see around Beacon: Beacon proposes to design log entries as events, as subclasses of BeaconSignal. If nothing else exists it is good. We will see in logs collection of such events. But what to do with existing domain events which has no relation to logs? How to log them if we decide to do it? They can be added to log inside WrapperSignal. But then we will see in logs mix of normal events which created specially for logs and WrapperSignal's containing original application events. But both type of events belong to same application. We definitely want to see them and to work with them in same way everywhere (especially inside logs) Tudor what do you think about this problem? Maybe I misunderstood Beacon.
Hi Denis,
On Apr 28, 2016, at 4:43 PM, Denis Kudriashov <dionisiydk@gmail.com> wrote:
2016-04-28 14:51 GMT+02:00 Tudor Girba <tudor@tudorgirba.com>: It is not the most elegant solution, but it is very malleable and good enough for debugging purposes. If we would have instance-based filtering for announcements, we could filter based on that without any extra effort. Also, if we would have a composition mechanism in place, we could build these objects with a more elegant API.
Regarding your statement of logging domain objects, you will have to store these objects with the additional information somewhere, and that will be a wrapper class. I do not see the difference with the Signal.
Difference with Beacon is that users will not depends on objects from logging library. Nobody needs to subclass core components like Signal. Instead domain objects will be added to logs inside general LogEntry instances which will be hidden from user and only available inside logs. And LogEntry will allow include additional information to itself by appropriate logging API.
Question is: does it better? And this is what problem I see around Beacon:
Beacon proposes to design log entries as events, as subclasses of BeaconSignal. If nothing else exists it is good. We will see in logs collection of such events. But what to do with existing domain events which has no relation to logs? How to log them if we decide to do it?
They can be added to log inside WrapperSignal. But then we will see in logs mix of normal events which created specially for logs and WrapperSignal's containing original application events. But both type of events belong to same application. We definitely want to see them and to work with them in same way everywhere (especially inside logs)
Tudor what do you think about this problem? Maybe I misunderstood Beacon.
Thanks for the dialogue. I think the most important part is to identify concerns and now we are getting concrete. So, letâs see :). Your LogEntry is exactly the same as BeaconSignal. There is no difference. You will also need to transport the LogEntry from your application to the logger object. Beacon reuses the Announcement framework to do just that. If you avoid the Announcement framework, you will implement another engine that has essentially the same responsibility. I think it is better to consolidate in this case. So, I see no downside of using Beacon for your purpose. But, I think there is more. One example where we have an event that is often worthwhile preserving is an Exception. In Beacon there is an out-of-the-box ExceptionSignal. This is not just a wrapper around the exception, but it also decides what to log from an Exception. For example, in order to ensure that we can have proper navigation of the exception, we capture the RB nodes for each stack entry. This is a naive implementation and we should certainly improve it (for example, we would need to delegate the computation of the stack information as late as possible), but it exemplifies how when you log you want to choose what to log. It can be that in another situation, we want to log the whole context of the exception. Furthermore, because we have a typed signal, we can also have a Stack presentation that depends on the strategy we used to log, not on the object that we logged. I believe this is a recurrent case. Nothing would prevent us from logging the exception through a plain WrapperSignal either. Only in that case we would not have the extra information that the ExceptionSignal provides. So, from this point of view, the ability to create types of signals is not a limitation, but an added value. That is why in my message I said that we should encourage people to create typed signals, but we should not enforce that. You mentioned that maybe your event object has a timestamp already. This timestamp is not the same as the logging timestamp, and it should be treated separately. If it is the same, that situation is so rare that I doubt we should optimize the whole framework around such a problem. Does this make sense? Cheers, Doru -- www.tudorgirba.com www.feenk.com "Sometimes the best solution is not the best solution."
Hi Tudor. I think I super bad in explaining things because you not answer my question. As you said we should encourage people to create typed signals. I am not against it. But I try to explain that approach of Beacon is wrong. It is wrong to make this signals be subclasses of Beacon core component BeaconSignal. We have in Pharo 307 subclasses of Announcements (only 78 have some kind of time variable). Do not they all are signals for logging? But only way how to log them in Beacon is to wrap them by kink of WrapperSignal. Does my issue is clear now? At the end we will got logs with mix of normal events which created specially for logs and WrapperSignal's containing original application events. 2016-04-28 23:39 GMT+02:00 Tudor Girba <tudor@tudorgirba.com>:
Hi Denis,
On Apr 28, 2016, at 4:43 PM, Denis Kudriashov <dionisiydk@gmail.com> wrote:
2016-04-28 14:51 GMT+02:00 Tudor Girba <tudor@tudorgirba.com>: It is not the most elegant solution, but it is very malleable and good enough for debugging purposes. If we would have instance-based filtering for announcements, we could filter based on that without any extra effort. Also, if we would have a composition mechanism in place, we could build these objects with a more elegant API.
Regarding your statement of logging domain objects, you will have to store these objects with the additional information somewhere, and that will be a wrapper class. I do not see the difference with the Signal.
Difference with Beacon is that users will not depends on objects from logging library. Nobody needs to subclass core components like Signal. Instead domain objects will be added to logs inside general LogEntry instances which will be hidden from user and only available inside logs. And LogEntry will allow include additional information to itself by appropriate logging API.
Question is: does it better? And this is what problem I see around Beacon:
Beacon proposes to design log entries as events, as subclasses of BeaconSignal. If nothing else exists it is good. We will see in logs collection of such events. But what to do with existing domain events which has no relation to logs? How to log them if we decide to do it?
They can be added to log inside WrapperSignal. But then we will see in logs mix of normal events which created specially for logs and WrapperSignal's containing original application events. But both type of events belong to same application. We definitely want to see them and to work with them in same way everywhere (especially inside logs)
Tudor what do you think about this problem? Maybe I misunderstood Beacon.
Thanks for the dialogue. I think the most important part is to identify concerns and now we are getting concrete. So, letâs see :).
Your LogEntry is exactly the same as BeaconSignal. There is no difference. You will also need to transport the LogEntry from your application to the logger object. Beacon reuses the Announcement framework to do just that. If you avoid the Announcement framework, you will implement another engine that has essentially the same responsibility. I think it is better to consolidate in this case.
So, I see no downside of using Beacon for your purpose.
But, I think there is more. One example where we have an event that is often worthwhile preserving is an Exception. In Beacon there is an out-of-the-box ExceptionSignal. This is not just a wrapper around the exception, but it also decides what to log from an Exception. For example, in order to ensure that we can have proper navigation of the exception, we capture the RB nodes for each stack entry. This is a naive implementation and we should certainly improve it (for example, we would need to delegate the computation of the stack information as late as possible), but it exemplifies how when you log you want to choose what to log. It can be that in another situation, we want to log the whole context of the exception. Furthermore, because we have a typed signal, we can also have a Stack presentation that depends on the strategy we used to log, not on the object that we logged. I believe this is a recurrent case.
Nothing would prevent us from logging the exception through a plain WrapperSignal either. Only in that case we would not have the extra information that the ExceptionSignal provides. So, from this point of view, the ability to create types of signals is not a limitation, but an added value. That is why in my message I said that we should encourage people to create typed signals, but we should not enforce that.
You mentioned that maybe your event object has a timestamp already. This timestamp is not the same as the logging timestamp, and it should be treated separately. If it is the same, that situation is so rare that I doubt we should optimize the whole framework around such a problem.
Does this make sense?
Cheers, Doru
-- www.tudorgirba.com www.feenk.com
"Sometimes the best solution is not the best solution."
No, I did not suggest that you want to log strings. I simply said that this type of use case is different than the regular logging use case. I think it is important to treat these two separately because indeed when you debug you are in a prototyping mode and you want to go fast. In this situation, you do not want to have to create a separate class. But, for the long term logging you have different requirements and there you want to be more rigorous, and in that scenario creating a new class is acceptable. If we design a logging infrastructure the second use case is what we want to optimize around.
Indeed Logging is not just about replace Transcript show:
Of course, we should still think about the prototyping part. I found that it is often more interesting to log entire contexts (and have a post-mortem debugger) than individual objects. Nevertheless, with something as simple as:
object asBeaconSignal log.
It worked fine.
And if I really wanted to add extra information, I rudimentary did:
{âsome textâ . object } asBeaconSignal log.
Or even:
{âsome textâ . #someSymbol . 42 . object } asBeaconSignal log.
I got a similar but not based on array but with a block to handle extension without subclasses.
It is not the most elegant solution, but it is very malleable and good enough for debugging purposes. If we would have instance-based filtering for announcements, we could filter based on that without any extra effort. Also, if we would have a composition mechanism in place, we could build these objects with a more elegant API.
Regarding your statement of logging domain objects, you will have to store these objects with the additional information somewhere, and that will be a wrapper class. I do not see the difference with the Signal.
Cheers, Doru
-- www.tudorgirba.com www.feenk.com
"We can create beautiful models in a vacuum. But, to get them effective we have to deal with the inconvenience of reality."
2016-04-28 11:07 GMT+02:00 Tudor Girba <tudor@tudorgirba.com>:
But anyway with Trait you can't add timestamp to your domain object which is always required for logs (I think we all agree about timestamp).
We can indeed agree on timestamp, but as Sven said, we might need flexibility on how to capture it (DateAndTime vs ZTimestamp).
Domain objects can supply own timestamp to log entries. But both kinds of time should be polimorphic in some cases. By the way why we need multiple timestamp representation in system? Can we choose best option and use it anywhere? (But this question is not for this topic)
Hi,
On Apr 28, 2016, at 2:36 PM, Denis Kudriashov <dionisiydk@gmail.com> wrote:
2016-04-28 11:07 GMT+02:00 Tudor Girba <tudor@tudorgirba.com>: But anyway with Trait you can't add timestamp to your domain object which is always required for logs (I think we all agree about timestamp).
We can indeed agree on timestamp, but as Sven said, we might need flexibility on how to capture it (DateAndTime vs ZTimestamp).
Domain objects can supply own timestamp to log entries.
I do not understand this point. Could you clarify?
But both kinds of time should be polimorphic in some cases.
Certainly.
By the way why we need multiple timestamp representation in system? Can we choose best option and use it anywhere? (But this question is not for this topic)
Indeed, we know that we do not need both, but someone has to clean them up :). In any case, in some cases you might want a certain precision even if it costs, and in others you do not. So, having the initialization of the timestamp factored out would be a good thing. Cheers, Doru -- www.tudorgirba.com www.feenk.com "Obvious things are difficult to teach."
2016-04-28 14:42 GMT+02:00 Tudor Girba <tudor@tudorgirba.com>:
Domain objects can supply own timestamp to log entries.
I do not understand this point. Could you clarify?
I think you mention something different than I had in mind. My case was when anObject already has internal timestamp it can pass it to log entry (signal)
Le 28/4/16 à 10:13, Denis Kudriashov a écrit :
2016-04-27 20:50 GMT+02:00 stepharo <stepharo@free.fr <mailto:stepharo@free.fr>>:
And you say let's replace this "log object context" information with first class entities "typed signals". It means that for any possible case when I want to put something in log I should create class for new signal. It's just not practical.
why? MySpecialLog ... emit
What I am talking about is that I don't want create MySpecialLog for any MySpecialDomainObject which I want to log.
I do not get it. Inheritance is good and if you combine it with delegation you can rule part of the world. BasicLog timeStamp object: MySpecialLog what I want
2016-04-27 20:50 GMT+02:00 stepharo <stepharo@free.fr>:
Beacon introduce WrapperSignal to solve it. But it only provides target and timestamp. What I should do if I want to put little remark for my object? And what if I want to put little remark for ThisContextSignal?
My idea that logging should be as simple as possible and we not need another "everything is signal" concept here: it is restriction. Everything is object. And every object should be able to log.
In the minimalLog
MinimalLog object: MyCoolObject new; emit
no need of message
And for my example when I want mark ThisContextSignal with extra user message how I can achieve it?
what I can tell you is that I do not like the API I did for extending Log in SystemLogger. I will try to read your long email. Now I have the impression that wrapping an object in the log could be a way to offer extensibility. Le 26/4/16 à 15:26, Denis Kudriashov a écrit :
Hello.
I resumed discussion about SystemLogger and Beacon here http://forum.world.st/What-the-state-of-unifying-Beacon-with-SystemLogger-td....
I plan to unify both approaches by saving traditional terminology from SystemLogger and cool features from Beacon.
Let's think about logging API to log any object in the system. Most natural way is just send message #log to object itself:
anObject log
It would be nice replacement for Object>>logCr. But when we log some information we usually want to log it with little remark, importance level and (most important) timestamp. This information is kind of standard for logging domain. But it requires much more methods for logging API. So we need extra information to put together with objects:
1. timestamp 2. user message 3. importance level (debug, info, error, etc.) 4. whatever (process hash, process name for example) 5. sometimes it can be needed to put in log something different than object itself. (for example it can be just copy of object to not change state of log entry during app lifetime)
Here is possible API based on Object extensions. It has drawbacks but it is good to think about it too:
"it will put anObject in logs with default #info level"
anObject log
"it will put anObject in logs with default #info level and given user message" anObject logWith: 'something interesting was happened with anObject'
"inside block we can put any logging domain information from application and also override content by specific representation" anObject logBy: [:logEntry |
logEntry message: 'something interesting to be saved with our object'
logEntry content: anotherObject] "here logs with interest about anObject will receive logEntry with anotherObject instead of anObject"
And similar for different kind of levels:
anObject logForDebug. anObject logForDebugWith: 'some debug message' anObject logForDebugBy: [:logEntry | ]
anObject logAsError. anObject logAsError: 'object computation was wrong' anObject logAsErrorBy: [:logEntry | ]
And most general:
anObject logAs: LogLevel warn
anObject logAs: LogLevel warn with: 'something interesting' anObject logAs: LogLevel warn by: [:logEntry | ]
And in case of classic logging with strings only first expressions would be used:
'some info message' log. 'some debug message' logForDebug 'some error message' logAsError 'some warn message' logAs: LogLevel warn
Problem with this approach: it pollutes Object with 12 extra methods and it can be more. So maybe it is better to use current SystemLogger API based on class Log:
Log info: anObject Log info: anObject as: 'computation result' "as example" Log info: anObject as: [:logEntry |
logEntry message: 'something interesting to be saved with our object
logEntry content: anotherObject]
Log error: anObject
Log error: anObject as: 'computation was wrong''
Log error: anObject as: [:logEntry | ]
Comparing to original SystemLogger versions I separate user message from object content. It makes possible to log any object with extra user message. But anyway it not feels very well IMHO. And it requires three methods for each log level. Maybe we can put this methods into LogLevel itself:
Log info add: anObject Log info add: anObject as: 'computation result' Log info add: anObject as: [:logEntry |
logEntry message: 'something interesting to be saved with our object
logEntry content: anotherObject]
Log error add: anObject
Log error add: anObject as: 'computation was wrong''
Log error add: anObject as: [:logEntry | ]
And we can make short version for default logging level (which can be object specific):
Log add: anObject
Log add: anObject as: 'computation result'
Log add: anObject as: [:logEntry | ]
That's all. I hope we can produce best suitable API for object logging. Then we can think how to adopt SystemLogger or Beacon for it. Also think about this API in context that we can register specific loggers for specific objects and specific importance level.
Best regards, Denis
participants (7)
-
Denis Kudriashov -
Nicolai Hess -
Norbert Hartl -
Robert Withers -
stepharo -
Sven Van Caekenberghe -
Tudor Girba