Hello,
When using -linfo, I get this confusing output:
0.407 [ Info ][visionPC] Waiting for data, timeout 500000 microseconds
0.407 [ Info ][visionPC] trajectoryEstimation will be triggered when new
data is available on Shuttle Positions Port
0.407 [ Info ][visionPC] trajectoryEstimation will be triggered when new
data is available on Reset Port
The second and third messages are confusing because they are not related at
all to my "VisionPC" component,
and are not even generated by my code. They originate from the TaskContext
code. "VisionPC" just happens to be the last component name used in a log
output. The Logger seems to simply remember the last component name
specified and reuse it.
- Is there a way to avoid such confusing messages?
- Shouldn't the Logger reset the component name after each log output
message?
Regards,
Johan Cockx
Confusing log messages
On 7/01/2010, at 03:41 , Johan Cockx wrote:
> Hello,
>
> When using -linfo, I get this confusing output:
>
> 0.407 [ Info ][visionPC] Waiting for data, timeout 500000 microseconds
> 0.407 [ Info ][visionPC] trajectoryEstimation will be triggered when new data is available on Shuttle Positions Port
> 0.407 [ Info ][visionPC] trajectoryEstimation will be triggered when new data is available on Reset Port
>
> The second and third messages are confusing because they are not related at all to my "VisionPC" component,
> and are not even generated by my code. They originate from the TaskContext code. "VisionPC" just happens to be the last component name used in a log output. The Logger seems to simply remember the last component name specified and reuse it.
>
> - Is there a way to avoid such confusing messages?
> - Shouldn't the Logger reset the component name after each log output message?
>
> Regards,
> Johan Cockx
The current logger implementation does not correctly deal with multiple threads/componentns, and each setting the logger name. The new real-time logging implementation that I've been working on does not suffer this problem. Once we get that into the mainline, this problem will disappear.
HTH
Stephen
Confusing log messages
Stephen,
It is nice to hear that someone is already working on a solution. Now that
I understand the problem, I can live with it until your new implementation
is available.
If I understand you correctly, the new implementation will be maintaining a
logger name per thread. But doesn't that cause a problem for Methods that
are part of one component but executed in the thread of another?
Regards,
Johan
On Wed, Jan 6, 2010 at 8:29 PM, S Roderick <kiwi [dot] net [..] ...> wrote:
> On 7/01/2010, at 03:41 , Johan Cockx wrote:
>
> Hello,
>
> When using -linfo, I get this confusing output:
>
> 0.407 [ Info ][visionPC] Waiting for data, timeout 500000 microseconds
> 0.407 [ Info ][visionPC] trajectoryEstimation will be triggered when new
> data is available on Shuttle Positions Port
> 0.407 [ Info ][visionPC] trajectoryEstimation will be triggered when new
> data is available on Reset Port
>
> The second and third messages are confusing because they are not related at
> all to my "VisionPC" component,
> and are not even generated by my code. They originate from the TaskContext
> code. "VisionPC" just happens to be the last component name used in a log
> output. The Logger seems to simply remember the last component name
> specified and reuse it.
>
> - Is there a way to avoid such confusing messages?
> - Shouldn't the Logger reset the component name after each log output
> message?
>
> Regards,
> Johan Cockx
>
>
> The current logger implementation does not correctly deal with multiple
> threads/componentns, and each setting the logger name. The new real-time
> logging implementation that I've been working on does not suffer this
> problem. Once we get that into the mainline, this problem will disappear.
>
> HTH
> Stephen
>
Confusing log messages
On 7/01/2010, at 21:13 , Johan Cockx wrote:
> Stephen,
>
> It is nice to hear that someone is already working on a solution. Now that I understand the problem, I can live with it until your new implementation is available.
>
> If I understand you correctly, the new implementation will be maintaining a logger name per thread. But doesn't that cause a problem for Methods that are part of one component but executed in the thread of another?
Not quite. You log to a specific logger, which in turn has been configured to format its output a certain way (perhaps including its name), and to a particular logger source (eg file, socket, console). It is a much more configurable system, and will be real-time (subject to certain limitations). We are still working on this implementation (check out bugs 708, 728 and 733 - the implementation is spread across these. Particularly, look at the public git repo's that I've setup for Peter. They are listed in those bugs).
There is a bunch of additional details at http://www.orocos.org/wiki/rtt/rtt-20/real-time-logging
HTH
S