Bug #1497
Receive and Deliver-Timestamps not set correctly
| Status: | Resolved | Start date: | 05/13/2013 | |
|---|---|---|---|---|
| Priority: | Normal | Due date: | ||
| Assignee: | J. Moringen | % Done: | 100% | |
| Category: | Common Lisp | |||
| Target version: | rsb-0.9 |
Description
I am not entirely sure which part is causing this, but I am using bag-play to replay old log files and messages from these log files are synced using timesync. Looking at the output of timesync it seems that receive and deliver timestamps are not set properly:
Event
Scope : /my/out/sync/vfoa/
Id : 2D8F70FA-E789-5BA6-99FA-A8ADC3FF310A
Sequence-Number: 39
Origin : 1D50F9F3-25F1-45D8-A65C-933A5F9843C4
Method : N/A
Timestamps
Create : 2013-05-13T17:31:33.336956+02:00
Send : 2013-05-13T17:31:33.337014+02:00
Receive: 2013-05-13T17:31:33.390350+02:00
Deliver: 2013-05-13T17:31:33.390356+02:00
Meta-Data
Rsb.Transport.Payload-Size: 808
Rsb.Transport.Wire-Schema : .rsb.protocol.collections.EventsByScopeMap
Rsb.Wire-Schema : .rsb.protocol.collections.EventsByScopeMap
Causes
DF9DA95A-2B53-55F0-A294-6063345D347A
B1AF34F2-6FD2-5231-A446-49B9A6E697CC
Payload (RSB.PROTOCOL.COLLECTIONS:EVENTS-BY-SCOPE-MAP)
Events by Scope (2 Scopes)
Scope "/monitoring/augit/volhumavipsreleasesy3demobinrsbvfoacomponent/3193/"
Event
Scope : /monitoring/augit/volhumavipsreleasesy3demobinrsbvfoacomponent/3193/
Id : DF9DA95A-2B53-55F0-A294-6063345D347A
Sequence-Number: 61
Origin : E575EEA6-92C8-4170-85C7-178AE20A62A3
Method : N/A
Timestamps
Create : 2013-05-13T17:31:33.228427+02:00
Send : 2013-05-13T17:31:33.228465+02:00
Receive : 2013-02-20T14:53:52.674019+01:00
Deliver : 2013-02-20T14:53:52.674022+01:00
Monitor-Finished: 2013-02-20T14:53:52.668788+01:00
You can see that the receive and deliver timestamps are from the original recording time even though the events were sent by bag-play today and hence also received today. I suspekt what happens is that bag-play already sets the timestamps before sending and the CPP socket transport on the receiving side does not override these timestamps.
Associated revisions
Format user timestamps distinguishably in formatting/event-style-meta-data.lisp
refs #1497
- formatting/util.lisp (header): updated copyright
(timestamp-name): new function; prepend "*" to names of user
timestamps
(framework-timestamp?): new function; predicates which indicates
whether a timestamp name names a framework timestamp - formatting/event-style-meta-data.lisp
(format-event event style-meta-data): apply `timestamp-name' to
timestamp names - test/formatting/style-meta-data.lisp
(test style-meta-data-root::smoke): added a case which checks
formatting of user timestamps
Fixed separation of framework- and user-timestamps in src/transport/*/conversion.lisp
refs #1497
- src/transport/socket/conversion.lisp (make-notification): be careful
to not store any framework timestamps in the user timestamp storage - src/transport/spread/conversion.lisp (header): updated copyright
(make-notification): like above - test/informer.lisp (test informer-root::send/event): ignore all
framework timestamps
History
#1 Updated by J. Wienke almost 11 years ago
- Category changed from Socket Transport to Common Lisp
- Assignee set to J. Moringen
Generally the problem does not exist in the core but is merely a display problem of the cl logger. What happens is that bag play puts the original timestamps into the user timestamps and the logger cannot handle framework and user timestamps with the same names.
#2 Updated by J. Moringen almost 11 years ago
- Status changed from New to In Progress
- % Done changed from 0 to 30
#3 Updated by J. Moringen almost 11 years ago
- Status changed from In Progress to Feedback
- % Done changed from 30 to 100
@Johannes: Please check whether these changes fix the problem for you.
#4 Updated by J. Wienke almost 11 years ago
- Status changed from Feedback to Resolved
Looks correct to me now.