I'm trying to correlate start and stop events and having a much harder time than what the documentation implies in order to make sure that the correlations are accurate. Say I have 4 events, as follows:
[service timestamp] |[event]|[item]|[consoleID]|[logonID]|[clientTimestamp]
2010/06/18 22:17:08.041|LS-XUBF|foo |0635A84D13 |2 |1CB0F33E1376C4C
2010/06/18 22:17:08.041|LS-XUCF|foo |0635A84D13 |2 |1CB0F33E1DEDC8F
2010/06/15 19:54:24.178|LS-XUBF|foo |0635A84D13 |2 |1CB0CC475A3ECA0
2010/06/15 19:54:24.178|LS-XUCF|foo |0635A84D13 |2 |1CB0CC475F2180D
LS-XUBF is the start event, and LS-XUCF is the end event. My goal is to use transaction to group them as follows:
2010/06/15 19:54:24.178|LS-XUBF|foo|0635A84D13|2|1CB0CC475A3ECA0
2010/06/15 19:54:24.178|LS-XUCF|foo|0635A84D13|2|1CB0CC475F2180D
2010/06/18 22:17:08.041|LS-XUBF|foo|0635A84D13|2|1CB0F33E1376C4C
2010/06/18 22:17:08.041|LS-XUCF|foo|0635A84D13|2|1CB0F33E1DEDC8F
I've tried several approaches, with limited success. I think it has something to do with the order that the logs appear in the file, rather than the timestamps on the events.
"transaction ConsoleId LogonId Item startswith=LS-XUBF endswith=LS-XUCF" sounds like exactly what I want, but it appears to not let the start event and end event have the same timestamp. As a result, I get one transaction instead of two, with the start from the first collection and the end from the second collection. Adding "maxevents=2" to this transaction yields the same results. It looks like this:
2010/06/15 19:54:24.178|LS-XUBF|foo|0635A84D13|2|1CB0CC475A3ECA0
2010/06/18 22:17:08.041|LS-XUCF|foo|0635A84D13|2|1CB0F33E1DEDC8F
"transaction ConsoleId LogonId Item maxevents=2" groups them exactly how I want, but is error prone. It's not guaranteed that we'll see an LS-XUCF event after an LS-XUBF event. The process could start, but never finish and never send the event (for example, if the machine doing the logging loses all power). This is unlikely, but still possible, and I don't want my data invalidated.
"transaction ConsoleId LogonId Item maxevents=2 startswith=LS-XUBF" gets me a little closer - I thought this was a perfect way to solve the above inconsistency problem, but instead, I get this, which isn't really any better:
2010/06/18 22:17:08.041|LS-XUBF|foo|0635A84D13|2|1CB0F33E1376C4C
2010/06/15 19:54:24.178|LS-XUBF|foo|0635A84D13|2|1CB0CC475A3ECA0
2010/06/18 22:17:08.041|LS-XUCF|foo|0635A84D13|2|1CB0F33E1DEDC8F
"transaction ConsoleId LogonId Item maxevents=2 endswith=LS-XUCF" looks similar to the above.
2010/06/15 19:54:24.178|LS-XUCF|foo|0635A84D13|2|1CB0CC475F2180D
2010/06/15 19:54:24.178|LS-XUBF|foo|0635A84D13|2|1CB0CC475A3ECA0
2010/06/18 22:17:08.041|LS-XUCF|foo|0635A84D13|2|1CB0F33E1DEDC8F
"transaction ConsoleId LogonId Item maxevents=2 endswith=LS-XUBF" gives me the right results for some reason, but I can't figure out why and this isn't technically want I want.
... View more