[MNG-5626] Avoid negative durations or handle them correctly

• Type: Bug
• Status: Closed
• Priority: Minor
• Resolution: Fixed
• Affects Version/s: 3.2.1
• Fix Version/s: 4.0.0-rc-2
• Component/s: Logging
• Assignee: Guillaume Nodet
• Reporter: Christian Jung
• Created: 29/Apr/14 01:44
• Updated: 13/Dec/24 23:11
• Resolved: 13/Dec/24 23:11

Description

In issue MNG-5623 we reported an exception when printing the reactor summary if one of the times was negative.

I saw in one case, that the overall maven build time, as measured from outside (i.e. by our QuickBuild system) was -10.8 seconds. The corresponding reactor summary was:

13:55:25,184 INFO  - Reactor Summary:
13:55:25,184 INFO  -
13:55:25,184 INFO  - module1 ........................................... SUCCESS [ 5.911 s]
13:55:25,184 INFO  - module2 ........................................... SUCCESS [ 0.255 s]
13:55:25,184 INFO  - gpPlaygroundBase-lnx-x64-gcc4 ..................... SUCCESS [-27.-64 s]
13:55:25,185 INFO  - ------------------------------------------------------------------------
13:55:25,185 INFO  - BUILD SUCCESS
13:55:25,185 INFO  - ------------------------------------------------------------------------
13:55:25,185 INFO  - Total time: -20.-73 s
13:55:25,185 INFO  - Finished at: 2014-04-28T13:55:25+01:00
13:55:25,572 INFO  - Final Memory: 32M/439M
13:55:25,572 INFO  - ------------------------------------------------------------------------

The thing is quite hard to reproduce, the machines were virtual machines that have been running for quite a long time.

Our administrators suspected that just at this point, the local clock was synchronized with some outer source.

We should check if such negative durations can be avoided, and if not, they should be handled correctly.

Issue Links

• depends upon: MNG-5729 Measure (build time) durations with System.nanoTime only
• is related to: MNG-5623 Exception when printing Reactor Summary
• relates to: MNG-5623 Exception when printing Reactor Summary