ARM-software / tarmac-trace-utilities

Tools for analyzing and browsing Tarmac instruction traces.
Apache License 2.0
67 stars 22 forks source link

Tick from tarmac-vcd are not aligned with the one from tarmac log. #12

Closed vmoretbosch closed 1 year ago

vmoretbosch commented 1 year ago

Hi, I'm using tarmac-vcd on logs from simulation (RTL code of ARM M55 core).

The tarmac log looks this way : Tarmac Text Rev 3t 109 tic ES EXC [1] Reset R MSP_S 20000860 BR (00000788) T 144 tic ES (00000788:b508) T thrd_s: PUSH {r3,lr} <_start>

but the timestamp in the corresponding VCD do not match :

#0
b00000000000000000000000001101101 a
b00100000000000000000100001100000 .
#1
b00000000000000000000000010010000 a
1e
b00000000000000000000011110001000 f
b00000000000000001011010100001000 c
sPUSH\040{r3,lr}\040<_start> d

I would expect :

#109
b00000000000000000000000001101101 a
b00100000000000000000100001100000 .
#144
b00000000000000000000000010010000 a
1e
b00000000000000000000011110001000 f
b00000000000000001011010100001000 c
sPUSH\040{r3,lr}\040<_start> d

By doing so, waveforms from rtl simulation and from tarmac-vcd would be synced.

I've locally patched on my side :

--- a/tools/vcdwriter.cpp
+++ b/tools/vcdwriter.cpp
@@ -228,8 +228,9 @@ class VCDVisitor : public ParseReceiver {

     void operator()(const SeqOrderPayload &sop, OFF_T)
     {
-        tick();
-
+        //tick();
+        VCD.writeTime(sop.mod_time);
+  

It works fine on my particular case but I could not say if it would always work.

And by the way, thanks for sharing your trace utility tools. They are really helpful.

BR,

statham-arm commented 1 year ago

Thanks for the suggestion! I can see that that would be a useful change.

Unfortunately, I don't think your patch will always work, because tick() is called in other circumstances too: if a trace event causes multiple memory accesses then they're separated by additional calls to tick(), so that the address and data values can appear sequentially in the address bus fields of the VCD.

With your change as written, I think that would end up interleaving sequential timestamps invented by tick() with the values taken from the input trace, so that the final list of timestamps would be out of sequence.

So we'd need to deal with that kind of event in some other way. @Arnaud-de-Grandmaison-ARM, any ideas?

Arnaud-de-Grandmaison-ARM commented 1 year ago

Hi,

@statham-arm is right in his understanding. We could however optionally attempt to use the timestamp from the VCD, doing some best-effort when synthesizing the memory accesses. This will not be perfect, e.g. the memory accesses would have a +1 delta (instead of the actual time), but the waveform would still be readable, and most importantly for @vmoretbosch 's usecase, at the instruction-level granularity, both VCDs would line-up well which will dramatically improve the debugging experience.

I don't have an RTL-level tarmac trace handy at the minute, but if @vmoretbosch could give a try at the attached patch and let me know if this works that would be great ! Note that you will need to add --use-tarmac-timestamp to the command line when invoking tarmac-vcd. 0001-VCD-Optionally-use-the-instruction-timestamp-from-th.patch

P.S. : @vmoretbosch haven't we met in a previous life (VLSI) ?

vmoretbosch commented 1 year ago

Hi Arnaud.

I've tried your patch and it works fine. Tarmac dumps and RTL dumps are now correctly synced.

Thanks for your support.

P.S. : Yes, we've met in ancient time ;).

Arnaud-de-Grandmaison-ARM commented 1 year ago

I've pushed this patch to tarmac-trace-utilities.

Thanks Vincent !

Arnaud-de-Grandmaison-ARM commented 1 year ago

Feature request implemented, closing this issue.