Configurable simulation time resolution in logging

[LarsAsplund]

Support configuration of the log entry simulation time with respect to:

1. The unit used (fs, ps, ns, and so on)
2. The number of decimals used. For example, if the simulation time is 123456789 fs, the unit is set to ns, and the number of decimals is set to 2, the logged time should be 123.46 ns

If the unit parameter is of type time, we can create negative time constants with special meaning. For example, a constant auto that uses the unit that keeps the integer part of the time within the 0 - 999 range.

[LarsAsplund]

Let's say 123450 ps is to be displayed in ns with three decimals. Is 123.450 ns or 123.45 ns preferred? I.e. is the number of configured decimals the exact number or the maximum number?

I'm leaning towards 123.45 ns because if no number of decimals is provided, I'd like the default behavior to be "as many decimals as needed". That aligns with the behavior of to_string(123450 ps, ns), at least in the simulators I've tested. I don't think the standard is specific about this.

It also aligns with Python rounding:

>>> round(123.450, 3)
123.45

[tasgomes]

I can't think of any other case where the configured three decimals are the exact number apart from the case where you want to print a lot of timestamps and you would like that all numbers are vertically aligned with the same number of decimals:

#        115000 ps - tb                           -   TRACE - 0.00012345 ms
#        115000 ps - tb                           -   TRACE - 0.000123451 ms
#        115000 ps - tb                           -   TRACE - 0.000123452 ms
#        115000 ps - tb                           -   TRACE - 0.000123453 ms
#        115000 ps - tb                           -   TRACE - 0.000123454 ms
#        115000 ps - tb                           -   TRACE - 0.000123455 ms
#        115000 ps - tb                           -   TRACE - 0.000123456 ms
#        115000 ps - tb                           -   TRACE - 0.000123457 ms
#        115000 ps - tb                           -   TRACE - 0.000123458 ms
#        115000 ps - tb                           -   TRACE - 0.000123459 ms
#        115000 ps - tb                           -   TRACE - 0.00012346 ms
#        115000 ps - tb                           -   TRACE - 0.000123461 ms
#        115000 ps - tb                           -   TRACE - 0.000123462 ms
#        115000 ps - tb                           -   TRACE - 0.000123463 ms
#        115000 ps - tb                           -   TRACE - 0.000123464 ms
#        115000 ps - tb                           -   TRACE - 0.000123465 ms
#        115000 ps - tb                           -   TRACE - 0.000123466 ms
#        115000 ps - tb                           -   TRACE - 0.000123467 ms
#        115000 ps - tb                           -   TRACE - 0.000123468 ms
#        115000 ps - tb                           -   TRACE - 0.000123469 ms

But I don't think this is critical and everybody's OCD can live with it 😄

[LarsAsplund]

@tasgomes This is what working state looks like ("auto unit" mode with three decimals).

It wouldn't be difficult to add an extra space to 1.02 ps to get better alignment.

[LarsAsplund]

Looks a bit weird, doesn't it?

Maybe the fixed number is best after all?

[LarsAsplund]

Another issue is the fact that VHDL time is an integer number, n, times a unit. The range of n is typically larger (64 bits) than the range of integers (32 bits) which means that we can't extract that integer (divide by the resolution limit) and use normal arithmetic to get the real number to display. Even if we could, to_string of real may be displayed in scientific notation and that is not what we want. For the initial iteration I'm operating on the string directly which has two consequences:

1. The implementation is restricted to time units in the fs to sec range. These are related in powers of ten so n remains "the same". All we have to do is to figure out where to put the decimal point. I think this is a reasonable limitation. Who uses min and hr in their simulation? If they do, they can always configure the logging to use the "native" mode which falls back to using plain to_string.
2. Limiting the number of decimals is implemented using truncation rather than rounding. This is a bit more annoying even though limiting the number of decimals is the same as not caring about the exactness of the output. I'm considering implementing some big number arithmetic to provide correct rounding. It will slow things down but I don't think it matters. Currently, 1 million logs takes about 45 s on my laptop regardless if I use this feature or not. The difference is less than the variations in different runs. Maybe it takes a second or two more time but that is something we can live with considering that a real-life simulation with 1 million log entries will be a much larger and longer simulation.

[tasgomes]

@LarsAsplund It does look weird with extra spacing, therefore I think the fixed number approach would be more suitable for this.

1. The limitation to sec range sounds very reasonable.
2. I think it is up to the user to define how much precision is necessary which depends on the test case. Many times if we only care about the timestamps for logging purposes then rounding or truncating is probably an insignificant choice. This made me think about the other purpose of the timestamps which is the ability (in Modelsim) to double-click on the log line and make the cursor jump to that specific time on the waveform viewer. In that case, rounding or truncating can make the cursor move to the point in time before or after the event which can be misleading... but again in that case I think it is up to the user to select a better unit for the logging time format.

[LarsAsplund]

I agree. Fixed number of decimals and truncate to that width. If someone comes up with a good reason for why we need to round, we can always reconsider.

[LarsAsplund]

@tasgomes I pushed the code for the new time format configuration. Here is the upcoming documentation. Sounds good? If so, I will merge:

[tasgomes]

Hi @LarsAsplund, the documentation sounds sane to me.

I took the opportunity to test this quickly. I used commit 48bcaa5. Is this the most updated one?

I could not find most of the definitions mentioned in the documentation like log_time_unit, but I noticed that if I run an old test where I don't touch the newly support time format I get a warning that was not there before (v4.7.0):

It is like the default time unit is fs instead of being the simulator's time resolution.

[LarsAsplund]

No, you need to checkout 229a688

[tasgomes]

hum, I guess you were doing some rebasing and that commit 48bcaa5 got lost / not tracked anymore. This somehow broke our Gitlab mirroring of the VUnit repository, that is why I did not find the latest sources like 229a688. I fixed that and now our mirrored sim_time_format branch matches the Github sim_time_branch.

Basically, when you use the time unit fs in the log_handler_pkg-body.vhd like here, then Modelsim/Questa will throw an annoying warning at the beginning of the simulation, if the simulator time resolution is set to ps.

Do you see the same?

If I comment all lines that use fs, then the warning disappears.

[LarsAsplund]

I only tested with `ps` on Riviera-PRO and then there is no problem. Does Questa return time as`fs` when calling `time'image` despite a resolution of `ps`? Or does it complain about that return statement despite not being executed? The reason I have my own resolution_limit function is to maintain our VHDL-93 support for logging

…

On Fri, 9 Aug 2024, 15:59 Tiago Gomes, ***@***.***> wrote: hum, I guess you were doing some rebasing and that commit 48bcaa5 <48bcaa5> got lost / not tracked anymore. This somehow broke our Gitlab mirroring of the VUnit repository, that is why I did not find the latest sources like 229a688 <229a688>. I fixed that and now our mirrored sim_time_format branch matches the Github sim_time_branch. Basically, when you use the time unit fs in the log_handler_pkg-body.vhd like here <https://github.com/VUnit/vunit/blob/sim_time_format/vunit/vhdl/logging/src/log_handler_pkg-body.vhd#L13>, then Modelsim/Questa will throw an annoying warning at the beginning of the simulation, if the simulator time resolution is set to ps. image.png (view on web) <https://github.com/user-attachments/assets/71447477-c589-4b17-a61f-74af8c21ac19> Do you see the same? If I comment all lines that use fs, then the warning disappears. — Reply to this email directly, view it on GitHub <#1044 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/ABS7IWLEVXXFXDR6APBQCNTZQTDMHAVCNFSM6AAAAABLGWOZZGVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDENZYGAYTCNRSHE> . You are receiving this because you were mentioned.Message ID: ***@***.***>

[LarsAsplund]

@tasgomes I tested with Questa and saw the same issue so I pushed a new commit that "hides" the finer time units. See if it works for you as well.

[tasgomes]

Thanks @LarsAsplund, latest commit removed the warning.