Mantis Bugtracker

Einfache Problemansicht anzeigen Zu Notizen wechseln ] erweiterte Anzeige ] Problem-Historie ] Drucken ]
ID Kategorie Auswirkung Reproduzierbar Meldungsdatum Letzte Aktualisierung
0000069 [Bolt] general Unschönheit N/A 2011-01-11 00:10 2011-08-15 16:16
Reporter ne fat s Anzeigestatus öffentlich  
Bearbeitung durch xclerc
Priorität normal Lösung wird nicht behoben  
Status geschlossen   Produktversion
Zusammenfassung 0000069: Dynamic logger names
Beschreibung I don't know if this is useful to others or not, but I found I wanted to create dynamic loggers, but still use the syntax extension - this means allowing expressions in place of constant strings in the NAME section of the log line.

Also, I wanted to report the logger name that the log line was given in a logger at a higher level (if you know what I mean).

I attach a rushed patch that makes both of these minor changes, in case it is useful for others as well.
Zusätzliche Information
Tags Keine Tags zugeordnet.
Angehängte Dateien

- Problem-Beziehungen

-  Notiz
(0000218)
ne fat s (Reporter)
2011-01-11 00:13

Sorry, I don't seem to be able to attach files - and I pasted the patch in the wrong box. Oops. Here it is again:

diff -aubr bolt-src/src/bolt_pp.ml bolt-src-mod/src/bolt_pp.ml
--- bolt-src/src/bolt_pp.ml 2010-12-15 06:54:12.000000000 +0000
+++ bolt-src-mod/src/bolt_pp.ml 2010-12-17 05:38:32.527352999 +0000
@@ -51,7 +51,7 @@
   type attributes = {
       error : Ast.expr option;
       properties : Ast.expr option;
- name : string option;
+ name : Ast.expr option;
     }
 
   let no_attribute = { error = None; properties = None; name = None; }
@@ -69,7 +69,7 @@
   EXTEND Gram
     GLOBAL: expr;
     attr: [[ "EXCEPTION"; e = expr -> { no_attribute with error = Some e }
- | "NAME"; s = STRING -> { no_attribute with name = Some s }
+ | "NAME"; s = expr -> { no_attribute with name = Some s }
            | "PROPERTIES"; e = expr -> { no_attribute with properties = Some e } ]];
     expr: LEVEL "simple" [[ "LOG"; e = expr; l = LIST0 attr; "LEVEL"; lvl = UIDENT ->
           let attrs = List.fold_left merge no_attribute l in
@@ -79,7 +79,9 @@
             let basename = Filename.basename file in
             let logger = match attrs.name with
             | Some s -> s
- | None -> logger_name (String.capitalize (try Filename.chop_extension basename with _ -> basename)) in
+ | None ->
+ let name = logger_name (String.capitalize (try Filename.chop_extension basename with _ -> basename)) in
+ <:expr< $str:name$ >> in
             let line = string_of_int (Loc.start_line _loc) in
             let column = string_of_int ((Loc.start_off _loc) - (Loc.start_bol _loc)) in
             let properties = match attrs.properties with
@@ -98,7 +100,7 @@
             | Ast.ExStr _ -> e
             | _ -> raise (Stream.Error "constant string expected after \"LOG\"") in
             <:expr< Bolt.Logger.log
- $str:logger$
+ $logger$
               $level_code$
               ~file:$str:file$
               ~line:$int:line$
diff -aubr bolt-src/src/event.ml bolt-src-mod/src/event.ml
--- bolt-src/src/event.ml 2010-12-15 06:54:12.000000000 +0000
+++ bolt-src-mod/src/event.ml 2010-12-17 06:03:33.227352998 +0000
@@ -37,6 +37,7 @@
     timestamp : time;
     relative : int;
     level : Level.t;
+ orig_logger : string;
     logger : string;
     origin : string;
     file : string;
@@ -58,6 +59,7 @@
     timestamp = now;
     relative = time (now -. initial_time);
     level = level;
+ orig_logger = logger;
     logger = logger;
     origin = (match origin with Some x -> x | None -> logger);
     file = file;
@@ -101,6 +103,7 @@
     "time", Int64.to_string (time64 e.timestamp);
     "relative", string_of_int e.relative;
     "level", Level.to_string e.level;
+ "origlogger", e.orig_logger;
     "logger", e.logger;
     "origin", e.origin;
     "file", if e.file <> "" then e.file else "<nofile>";
diff -aubr bolt-src/src/event.mli bolt-src-mod/src/event.mli
--- bolt-src/src/event.mli 2010-12-15 06:54:12.000000000 +0000
+++ bolt-src-mod/src/event.mli 2010-12-17 06:05:06.897352999 +0000
@@ -28,6 +28,7 @@
     timestamp : time; (** Event timestamp. *)
     relative : int; (** Time elapsed between application start and event construction. *)
     level : Level.t; (** Event level. *)
+ orig_logger: string; (** Original logger name. *)
     logger : string; (** Logger name. *)
     origin : string; (** First logger that received the event. *)
     file : string; (** Location of event source. *)
@@ -68,6 +69,7 @@
     - ["time"] event timestamp;
     - ["relative"] time elapsed between initilization and event creation;
     - ["level"] event level;
+ - ["origlogger"] event orig_logger;
     - ["logger"] event logger;
     - ["origin"] first logger that received the event;
     - ["file"] event file;
(0000223)
xclerc (Administrator)
2011-01-11 19:42

Thanks for the idea (and the patch). I never found myself in such a situation where
I would like to have a dynamic logger name. In fact, even when not using the syntax
extension, the logger name is always a string constant for me.

So, I you can discuss it publicly, I would be very interested in reading a use case for
dynamic logger names. I also notice that (in your patch) you keep track of the original
name, and am wondering why you are then interested in having both names.

Finally, I have mixed feeling on how this features interacts with the fact that loggers
are organized in a hierarchy.

Would be glad to discuss these points on this page if it is OK with you.
(0000224)
ne fat s (Reporter)
2011-01-11 20:58

Yes, well, I wasn't sure if I was misunderstanding the intent or not, and so may be going about things in the wrong way. But my particular use case is this - I have a module representing a particular gambling strategy, and I may use that strategy on different events. I want to have the event (which is determined at run time) as part of the logger name - I don't want log messages for different events being mixed up. (In this case the strategy can be considered an abstract data type, and I want a different logger for each instance).

So that was why I desired dynamic logger names - but perhaps there's another way to go about it?

Then, for using the original name - again, using the example of the strategy, I have different sections in the strategy that deal with various aspects (essentially long functions) - I want to log progress through these functions for debugging purposes, and I want these to be denoted clearly in the log - but I don't always want a separate log file for each function, I'd like to have one log file for each strategy, but to use the logger name in the log to denote the section being logged.

I'm not really interested in having both names, it's true. I just didn't see a reason to remove the normal logger name - as I guessed there was a real reason for using the logger in which the log line gets written, as otherwise you wouldn't have written it that way :)

But using the original logger name, I can clearly denote sections of the application in a collated logfile, while still allowing separate loggers for particular sections.

I'm glad to discuss it, I've had a feeling I might be misinterpreting the intended use cases, or wasn't matching my use cases properly to the library.
(0000228)
xclerc (Administrator)
2011-01-19 06:59

Thanks for the detailed use case.

You refer to strategies dynamically chosen at runtime, are the names of these strategies
somewhat statically determined (thinking of "simulated-annealing", "taboo-search", etc),
or are these names also dynamic (thinking of "simulated-annealing-0.7", etc)?

In the former case, I think I would use a property, leading to something like:
    LOG "my_function" PROPERTIES ["strategy", "simulated-annealing"] LEVEL DEBUG
Then, you use properties in your configuration file:
    [Module]
    level=trace
    filter=all
    layout=pattern
    pattern=$(time) $(file) $(line) $(level) $(message) $(properties)
    output=file
    name=ouput.log

Then comes the problem of reviewing the log file(s) for debugging. If I understand what you
want to achieve, you want to have one file per strategy. Currently, it is not directly possible
(see more below) to use different files according to a property. You can only rely on the tool(s)
used to review the generated file to filter the information (thinking of grep, or chainsaw).


Another possibility, is for you to write a custom filter, or for me to provide a way to use
such a filter from the configuration file. If you intend to switch to the use of properties,
we can discuss this more thoroughly here.
(0000229)
xclerc (Administrator)
2011-01-19 07:05

My previous reply was, in some sense, the "canonical" way of doing things.
A more pragmatic may be to just use the "printf" capabilities of the "LOG"
statement with something like:
    LOG "my_function (using strategy %s)" strategy LEVEL DEBUG
where "strategy" is any expression with type "string" in the context of the
"LOG" statement.

But this clearly does no solve the question of multiple destination files.
Again, you would have to play with grep and/or chainsaw or the like.


Your use case is definitely interesting; I think the kind of discussion we are
having on this page should go in something like a "cookbook" section of the
manual.
(0000232)
ne fat s (Reporter)
2011-01-19 14:57

Hi, yes, the properties would help to differentiate the functions as part of a strategy, that's a good idea - the function doesn't need to be part of the logger name at all, and is completely static. Also, I don't actually use different files for functions, it's more of a theoretical idea - so at least for my personal use case properties are fine.

I considered using the printf solution, but after I'd already added the dynamic logger names for the strategy case, appending a '.<function>' to the name was less typing, and easier to read in the log file.

The instances of a strategy are completely dynamic. For example, I may have a strategy 'arbitrage1' implemented in module Arbitrage1 with a type t representing an instance of that strategy. I may create instances of these on various markets, determined completely dynamically (before I connect to an exchange I have no idea how many or which markets are available, and then, of those that are available the choice of which to trade is made by the user) - and here I think there should be a separate log file for each. So I would create a logger with name 'Arbitrage1.<market>' where market is the dynamic identifier for the market determined at run time. So in this case it seems reasonable to keep the identification of the strategy instance as part of the logger name, and to have a separate logger for it (though it would still be possible to combine log lines into a single Arbitrage1 logger through the logger hierarchy, if desired).

I will consider this some more, but one problem with the solution I have right now is that I need to create the logger in code, specifying the format in the source. This isn't as convenient as using a config file... I'll try and spend some more time considering this - I wonder if using a pattern in the log config to specify formats for loggers created dynamically is worthwhile. Sounds like a much larger change than my small patch though :)
(0000243)
xclerc (Administrator)
2011-08-15 16:16

With the release of version 1.2, I have decided not to implement dynamic logger name.
I feel that, even if sometime desirable, this is not the proper way to achieve separation
of events.

- Problem-Historie
Änderungsdatum Benutzername Feld Änderung
2011-01-11 00:10 ne fat s Neues Problem
2011-01-11 00:13 ne fat s Problemnotiz hinzugefügt: 0000218
2011-01-11 00:14 ne fat s Problem beobachten: ne fat s
2011-01-11 19:42 xclerc Problemnotiz hinzugefügt: 0000223
2011-01-11 19:42 xclerc Bearbeitung durch => xclerc
2011-01-11 19:42 xclerc Status neu => Rückmeldung
2011-01-11 20:58 ne fat s Problemnotiz hinzugefügt: 0000224
2011-01-19 06:59 xclerc Problemnotiz hinzugefügt: 0000228
2011-01-19 07:05 xclerc Problemnotiz hinzugefügt: 0000229
2011-01-19 14:57 ne fat s Problemnotiz hinzugefügt: 0000232
2011-08-15 16:16 xclerc Problemnotiz hinzugefügt: 0000243
2011-08-15 16:16 xclerc Status Rückmeldung => geschlossen
2011-08-15 16:16 xclerc Lösung offen => wird nicht behoben
2011-08-15 16:16 xclerc Behoben in Version => 1.2


Mantis 1.1.7[^]
Copyright © 2000 - 2008 Mantis Group
Powered by Mantis Bugtracker