Log Parsing tool available

[X.l.r.8]

Yeah, fat-32 GUID boot. My try other formats .

 

[tomsax]

Version 1.2.6 of my log parser tool is available from the VMSParser page.

- correct mangled timestamps due to GPS Week 1024 wrapping issue
- improve end SOC for drive sessions
- improve odometer range shown in transient section summary line
- fix bug in Mac version parsing dates for -s and -e options
- add -a option to dump out all records (in the specified section)

 

[gregd]

Thank you!

 

[tomsax]

Version 1.2.7 of my log parser tool is available from the VMSParser page.

- increase histogram (-b) support from 10 years to 20 years

Thanks to slcasner for the bug report.

 

[Electric Swede]

I downloaded the VMSParser and have the executable on my desktop but when I launch it the command promt screen shows up for a second and then disapears. Turned off ALL my McAfee protection and tried it again but NO!

Is there an obvious trick I'm not seeing?

 

[tomsax]

You have to run VMSParser from the terminal (macOS) or command prompt (Windows).

If you just run it from the Finder/Explorer (by double-clicking for example) it will do what you describe: open a temporary window, execute the command with no arguments so it spews out the default help text and exits, then the system closes the window. That's normal system behavior and not an issue with malware protection.

See the "Using a Command Line App" section on the VMSParser web page.

 

[gregd]

It also runs on Linux under Wine from the shell, e.g.

wine ~/bin/VMSParser.exe 202006232203.tar
​

I find it's easiest (least typing) to be in the directory where the log is, and with the parser in your ~/bin directory.

 

[einhalv]

It also runs on Linux under Wine from the shell, e.g.

wine ~/bin/VMSParser.exe 202006232203.tar
​

I find it's easiest (least typing) to be in the directory where the log is, and with the parser in your ~/bin directory.

Agreed. I also put a script named vmsparser with the content
---
#!/bin/bash
wine ~/bin/VMSParser.exe $@
--
in my bin directory and made sure the directory is in my path.
Then it is sufficient to write , e.g.,
vmsparser 202006232203.tar
in the directory where the log is.

 

[Roadrunner13]

@tomsax ,

I have a bunch of corrupted log files due to GPS bug and I see you released a version that parses them correctly.
It works nicely to output records again in plain text with proper dates!!!
THANK YOU for this great update!
I just finished updating my GPS firwmare with Steve's cable so I won't have any date corrupted logs anymore!

If you feel like tinkering with your parser again, it would be really cool to regenerate the vms_log file with the date record corrections, so we could use it with Doug's graph tool also.
You likely don't have the binary record write capability but maybe it's possible to just read/write the binary while adding the binary offset to the date field...maybe that wouldn't be so bad...

I tried the '-j output' flag but didn't get it to output anything I could use whether I used clean files or GPS corrupted ones.
I probably didn't understand the syntax or the purpose of it properly.

If you ever put this code on github, let us know here so we can (try to) contribute (I'm assuming this in C for some reason).

 

[slcasner]

I think I provided the sample code to work around the date offset to Doug. I know I've provided it a couple of times in this forum.

 

[Roadrunner13]

I think I provided the sample code to work around the date offset to Doug. I know I've provided it a couple of times in this forum.

Yes, he did. He mentions you in his release note too .
The text output from the vmsparser has been updated and works perfectly (as far as I've seen).

I'm asking about recreating binary vms_log file.

 

[slcasner]

I think it would not be too difficult to rewrite the log files with corrected timestamps. In my own parser I use the nice libarchive package (originally from the FreeBSD community) to take apart the tar file, so it would require more code to reconstruct the tar file while modifying the timestamps. I think Tom's code might be a more convenient platform because, if I remember correctly, he doesn't bother to unpack the tar file but instead just scans through it until he hits log data. I'm not sure, though, given what the -j option claims to do.

 

[tomsax]

The -j option was created early on, before I starting parsing the vmslog file in place within the tar file. The idea is to write out a single flat file with all of the log entries from multiple files, but I don't know if it still works, or ever worked.

The code that fixes the dates doesn't know where the record came from and the code that knows where the record is doesn't even know the timestamp got fixed up. It's even more complex because of difference between how the macOS and Windows builds do the file I/O.

Everything I know about the log files is documented on my web site, so anyone who codes can write their own parser (or repair tool) in their favorite language.

If someone does write a tool to fix the mangled timestamps, don't forget to recalculate and update the checksums for those records.

 

[slcasner]

Tom, sorry for my incorrect assumption.

 

[tomsax]

Tom, sorry for my incorrect assumption.

No problem, it was a reasonable theory.

 

[einhalv]

The parser deals well with the rollover issue on my log-files, but I have noted that there are a handful of entries with date December 2, 2007 in the text output which must have another cause. Here is an example:

08/21/2020 13:13:05 | 1598008385 | ERR | error code 428 1 bytes
12/02/2007 09:56:24 | 1196585784 | ERR | error code 1 8 bytes
08/21/2020 15:24:04 | 1598016244 | ERR | error code 55
08/21/2020 15:24:09 | 1598016249 | ERR | error code 52 (VMS: VMS restarted)

It is tempting to interpret it as a default date appearing in the initial phase of a reboot before the correct date has been set.

 

[slcasner]

08/21/2020 13:13:05 | 1598008385 | ERR | error code 428 1 bytes
12/02/2007 09:56:24 | 1196585784 | ERR | error code 1 8 bytes
08/21/2020 15:24:04 | 1598016244 | ERR | error code 55
08/21/2020 15:24:09 | 1598016249 | ERR | error code 52 (VMS: VMS restarted)

Were those records present in the file in the sequence as shown? I'm not sure what error code 1 is, but your theory about a record being logged before the time is set makes sense. Often such timestamps are 0, so 1/1/1970, but maybe the 2007 date is when the VMS code was initially completed or some such.

I don't know about that error string for code 52, either.

 

[einhalv]

Yes, all in the sequence they came out of the parser. I just cut out from the line before to the line after. The codes 5X are all related to "No data fault" from some module and the code 1 is "Custom alert" according to Gruber's list . This is one example out five where the 2007-date appears. The other examples have more of these entries in a sequence, here is one with two:
09/18/2019 08:57:25 | 1568789845 | ERR | error code 1144 6 bytes
12/02/2007 13:56:23 | 1196600183 | ERR | error code 1 8 bytes
12/02/2007 13:56:46 | 1196600206 | ERR | error code 52 (VMS: VMS restarted)
09/19/2019 15:28:53 | 1568899733 | ERR | error code 104 7 bytes
Both examples that I have given are from times when the car was at the service center. Another example is from when I know that car was down and then turned on. Yet another one is from a time when I believe the battery was changed (before I bought it). BTW, code 52 is *not* in all examples.

It would be interesting if someone else has seen the same phenomenon.

 

[slcasner]

I don't have any dates near 2007. I have some instances of very small timestamps:

10/07/2013 09:35:51 | 1381163751 | ERR | error code 1660 6 bytes
10/12/2013 22:17:10 | 1381641430 | ERR | error code 1124 6 bytes
------------------- | 2 | ERR | error code 420
------------------- | 4 | ERR | error code 1 8 bytes
------------------- | 27 | ERR | error code 52 (VMS: VMS restarted)
10/23/2013 09:43:07 | 1382546587 | ERR | error code 1094 6 bytes
10/31/2013 21:03:00 | 1383278580 | ERR | error code 1660 6 bytes

I also have one instance of a couple of timestamps in 2033:

11/04/2014 12:13:47 | 1415132027 | ERR | error code 1556 8 bytes
11/04/2014 12:13:47 | 1415132027 | ERR | error code 1557 8 bytes
06/09/2033 22:48:53 | 2001995333 | ERR | error code 420
06/09/2033 22:48:54 | 2001995334 | ERR | error code 1 8 bytes
11/04/2014 14:59:32 | 1415141972 | ERR | error code 52 (VMS: VMS restarted)
11/04/2014 15:01:05 | 1415142065 | ERR | error code 1103 6 bytes

And during the time when my 3.0 battery was being installed the date was in 2033 continuously.

 

[einhalv]

Sounds like very much the same phenomenon, just different timestamps. I suppose this is to be expected then. Since the spurious dates are bracketed by the dates before and after, the log entries are still useful information.