Uploaded image for project: 'Thorntail'
  1. Thorntail
  2. THORN-1899

MP metrics: the "unit" parameter of the @Timed annotation is ignored, Prometheus and JSON output disagree

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Blocker
    • Resolution: Done
    • Affects Version/s: 2018.3.3
    • Fix Version/s: 2018.4.1
    • Component/s: microprofile
    • Labels:
      None

      Description

      As part of a Swarm application, I have a simple application metric such as

      @ApplicationScoped
      public class HelloService {
          @Timed(unit = MetricUnits.MILLISECONDS, name = "hello-time", absolute = true, displayName = "Hello Time", description = "Time of hello invocations")
          public String hello() throws InterruptedException {
              Thread.sleep(new Random().nextInt(100) + 1);
              return "Hello from timed method";
          }
      }
      

      The intent is for the method to take roughly between 1 and 100 millis, and have the duration reported in millis as well.

      However, when I run that -swarm.jar uberjar, trigger the timed method several times and then issue request to localhost:8080/metrics, I see:

      {
          "application": {
              "hello-time": {
                  ...
                  "max": 98169935, 
                  "min": 2095416, 
                  ...
              }
          }, 
          ...
      }
      

      Clearly the times are in nanoseconds, which is the default for the @Timed annotation.

      Yet the metric metadata say the unit is millis, like specified in the annotation:

      {
          "application": {
              "hello-time": {
                  "description": "Time of hello invocations", 
                  "displayName": "Hello Time", 
                  "type": "timer", 
                  "unit": "milliseconds"
              }
          }, 
          "base": {
              ...
          }
      }
      

      I believe this itself is a blocking issue, though I can't find a single place in the MP Metrics spec that would conclusively confirm or refute.

      I have another argument, though, that makes it clear that there's definitely something wrong: if I request the metrics in the Prometheus format, I see:

      ...
      application:hello_time_min_seconds 2095.416
      application:hello_time_max_seconds 98169.935
      ...
      

      This is very clearly wrong – the invocations don't take thousands of seconds!

      I believe that, when converting the values to seconds as MP Metrics spec requires, WildFly Swarm acted as if the metric was in millis (per the metadata!). Problem is that the values are actually in nanos!

      To conclude, I think these 2 wrong outputs are actually caused by a single problem.

        Gliffy Diagrams

          Attachments

            Activity

              People

              • Assignee:
                mszynkie Michal Szynkiewicz
                Reporter:
                lthon Ladislav Thon
              • Votes:
                1 Vote for this issue
                Watchers:
                2 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: