I can only suggest to make it even longer :) it is helpful to print the time before the log level, something like this:
00:00:07.78| INFO: Clustered transforms size: 785 00:00:07.78| DEBUG: found trans with RMSD: 2.30 -0.18 0.07 -0.19 -1.23 1.71 1.52
it gives you an idea where the time is spent. I know you can easily get it from profiling, but you don't run profiler on every run, so this is very helpful to keep you aware of run times.
also I wouldn't worry about long lines, that's what we have big monitors for :)
On Thu, Jul 5, 2012 at 10:04 AM, Daniel Russel drussel@gmail.com wrote: > When a log message is printed out you get something like > Model::evaluate > MyRestraint::evaluate > Found a fit with orientation X > another message > end MyRestraint::evaluate > end Model::evaluate > > As for controlling what gets printed, each thing derived from > IMP::base::Object has its own log level. This should be used to control the > logging of every method on the object (and methods called by them that don't > have something else setting their log level). Doing this requires an > IMP_OBJECT_LOG macro invocation at the start of the method which has some > cost (both in terms of putting the line in and at runtime), so not all > methods have it. I tend to put it in the methods that are more than ~10 > lines in the objects I write. > > You can also use SetLogState raii objects to locally control the logging > produced (eg disable it for some part of your code). > > On Jul 5, 2012, at 8:34 AM, Barak Raveh wrote: > > Daniel, > What exactly is the context? I guess this is what I really had in mind > personally, but I'm not 100% sure what you mean by it, or how to use it > (couldn't find any ref to it in the man page on logging). Is it someway of > getting to know in which context a log message from a certain class was > called? Is it possible to mute certain contexts in runtime (e.g., now I > don't want to see logging from this class but only from that class, etc.). > Barak > > On Thu, Jul 5, 2012 at 7:10 AM, Daniel Russel drussel@gmail.com wrote: >> >> I'm not sure I see the problem this is supposed to solve. And it would >> make often already long log lines even longer and harder to scan visually >> since the prefix is no longer meaningful. What is a scenario when you want >> to use this? >> >> And why add the log level part? The context lines can't be readily tagged >> with the log level since there can be messages with several different levels >> within a different context (and they aren't all known when the line is >> produced). And I think it is too much information to stick all into one >> line. So I see that we can set it up so that you can get something that >> looks like WARN level output when running in TERSE. In addition, running >> things with VERBOSE slows runtimes down rather noticeably, so I'm not sure >> you would want to do that routinely while only looking at terse messages, >> for example. >> >> On the implementation side, log messages are already scanned for newlines >> and indentation prefixes inserted, so adding other prefixes is easy. >> >> On Jul 3, 2012, at 3:51 PM, Javier Velazquez wrote: >> >> > >> > I have a simple proposal. write the granularity ad the beginning of each >> > log message. Something like >> > >> > LOG:TERSE blah blah >> > >> > Then a couple of "greps" would make going through all the output less >> > painful, wouldn't it? >> > >> > _______________________________________________ >> > IMP-dev mailing list >> > IMP-dev@salilab.org >> > https://salilab.org/mailman/listinfo/imp-dev >> >> >> _______________________________________________ >> IMP-dev mailing list >> IMP-dev@salilab.org >> https://salilab.org/mailman/listinfo/imp-dev > > > > > -- > Barak > _______________________________________________ > IMP-dev mailing list > IMP-dev@salilab.org > https://salilab.org/mailman/listinfo/imp-dev > > > > _______________________________________________ > IMP-dev mailing list > IMP-dev@salilab.org > https://salilab.org/mailman/listinfo/imp-dev >