private void logTimingInfo()

in uimaj-as-jms/src/main/java/org/apache/uima/adapter/jms/client/BaseUIMAAsynchronousEngineCommon_impl.java [1842:1994]


  private void logTimingInfo(Message message, ProcessTrace pt, ClientRequest cachedRequest)
          throws Exception {
    clientSideJmxStats.incrementTotalNumberOfCasesProcessed();

    if (message.getStringProperty(AsynchAEMessage.CasReference) != null) {
      String casReferenceId = message.getStringProperty(AsynchAEMessage.CasReference);
      if (clientCache.containsKey(casReferenceId)) {
        ClientRequest cacheEntry = (ClientRequest) clientCache.get(casReferenceId);
        if (cacheEntry == null) {
          return;
        }
        // Add time waiting for reply to the client JMX stats
        long timeWaitingForReply = cacheEntry.getTimeWaitingForReply();
        clientSideJmxStats.incrementTotalTimeWaitingForReply(timeWaitingForReply);
        // Add CAS response latency time to the client JMX stats
        long responseLatencyTime = cacheEntry.getSerializationTime() + timeWaitingForReply
                + cacheEntry.getDeserializationTime();
        clientSideJmxStats.incrementTotalResponseLatencyTime(responseLatencyTime);
        if (UIMAFramework.getLogger(CLASS_NAME).isLoggable(Level.FINEST)) {
          UIMAFramework.getLogger(CLASS_NAME)
                  .logrb(
                          Level.FINEST,
                          CLASS_NAME.getName(),
                          "handleProcessReply",
                          JmsConstants.JMS_LOG_RESOURCE_BUNDLE,
                          "UIMAJMS_timer_detail_FINEST",
                          new Object[] { message.getStringProperty(AsynchAEMessage.MessageFrom),
                              "Total Time Waiting For Reply",
                              (float) timeWaitingForReply / (float) 1000000 });
        }
        pt.addEvent("UimaEE", "process", "Total Time Waiting For Reply",
                (int) (timeWaitingForReply / 1000000), "");
      }
    }
    if (message.propertyExists(AsynchAEMessage.TimeToSerializeCAS)) {
      long timeToSerializeCAS = message.getLongProperty(AsynchAEMessage.TimeToSerializeCAS);
      if (UIMAFramework.getLogger(CLASS_NAME).isLoggable(Level.FINEST)) {
        UIMAFramework.getLogger(CLASS_NAME).logrb(
                Level.FINEST,
                CLASS_NAME.getName(),
                "handleProcessReply",
                JmsConstants.JMS_LOG_RESOURCE_BUNDLE,
                "UIMAJMS_timer_detail_FINEST",
                new Object[] { message.getStringProperty(AsynchAEMessage.MessageFrom),
                    "Time To Serialize Cas", (float) timeToSerializeCAS / (float) 1000000 });
      }
      pt.addEvent("UimaEE", "process", "Time To Serialize Cas",
              (int) (timeToSerializeCAS / 1000000), "");
      // Add the client serialization overhead to the value returned from a service
      timeToSerializeCAS += cachedRequest.getSerializationTime();
      clientSideJmxStats.incrementTotalSerializationTime(timeToSerializeCAS);
    }
    if (message.propertyExists(AsynchAEMessage.TimeToDeserializeCAS)) {
      long timeToDeserializeCAS = message.getLongProperty(AsynchAEMessage.TimeToDeserializeCAS);
      if (UIMAFramework.getLogger(CLASS_NAME).isLoggable(Level.FINEST)) {
        UIMAFramework.getLogger(CLASS_NAME).logrb(
                Level.FINEST,
                CLASS_NAME.getName(),
                "handleProcessReply",
                JmsConstants.JMS_LOG_RESOURCE_BUNDLE,
                "UIMAJMS_timer_detail_FINEST",
                new Object[] { message.getStringProperty(AsynchAEMessage.MessageFrom),
                    "Time To Deserialize Cas", (float) timeToDeserializeCAS / (float) 1000000 });
      }
      pt.addEvent("UimaEE", "process", "Time To Deserialize Cas",
              (int) (timeToDeserializeCAS / 1000000), "");
      // Add the client deserialization overhead to the value returned from a service
      timeToDeserializeCAS += cachedRequest.getDeserializationTime();
      clientSideJmxStats.incrementTotalDeserializationTime(timeToDeserializeCAS);
    }
    if (message.propertyExists(AsynchAEMessage.TimeWaitingForCAS)) {
      long timeWaitingForCAS = message.getLongProperty(AsynchAEMessage.TimeWaitingForCAS);
      if (UIMAFramework.getLogger(CLASS_NAME).isLoggable(Level.FINEST)) {
        UIMAFramework.getLogger(CLASS_NAME).logrb(
                Level.FINEST,
                CLASS_NAME.getName(),
                "handleProcessReply",
                JmsConstants.JMS_LOG_RESOURCE_BUNDLE,
                "UIMAJMS_timer_detail_FINEST",
                new Object[] { message.getStringProperty(AsynchAEMessage.MessageFrom),
                    "Time to Wait for CAS", (float) timeWaitingForCAS / (float) 1000000 });
      }
      pt.addEvent("UimaEE", "process", "Time to Wait for CAS", (int) (timeWaitingForCAS / 1000000),
              "");
    }
    if (message.propertyExists(AsynchAEMessage.TimeInService)) {
      long ttimeInService = message.getLongProperty(AsynchAEMessage.TimeInService);
      if (UIMAFramework.getLogger(CLASS_NAME).isLoggable(Level.FINEST)) {
        UIMAFramework.getLogger(CLASS_NAME).logrb(
                Level.FINEST,
                CLASS_NAME.getName(),
                "handleProcessReply",
                JmsConstants.JMS_LOG_RESOURCE_BUNDLE,
                "UIMAJMS_timer_detail_FINEST",
                new Object[] { message.getStringProperty(AsynchAEMessage.MessageFrom),
                    "Time In Service", (float) ttimeInService / (float) 1000000 });
      }
      pt.addEvent("UimaEE", "process", "Time In Service", (int) (ttimeInService / 1000000), "");

    }
    if (message.propertyExists(AsynchAEMessage.TotalTimeSpentInAnalytic)) {
      long totaltimeInService = message.getLongProperty(AsynchAEMessage.TotalTimeSpentInAnalytic);
      if (UIMAFramework.getLogger(CLASS_NAME).isLoggable(Level.FINEST)) {
        UIMAFramework.getLogger(CLASS_NAME).logrb(
                Level.FINEST,
                CLASS_NAME.getName(),
                "handleProcessReply",
                JmsConstants.JMS_LOG_RESOURCE_BUNDLE,
                "UIMAJMS_timer_detail_FINEST",
                new Object[] { message.getStringProperty(AsynchAEMessage.MessageFrom),
                    "Total Time In Service", (float) totaltimeInService / (float) 1000000 });
      }
      pt.addEvent("UimaEE", "process", "Total Time In Service",
              (int) (totaltimeInService / 1000000), "");
    }
    if (message.propertyExists(AsynchAEMessage.TimeInProcessCAS)) {
      long totaltimeInProcessCAS = message.getLongProperty(AsynchAEMessage.TimeInProcessCAS);
      if (UIMAFramework.getLogger(CLASS_NAME).isLoggable(Level.FINEST)) {
        UIMAFramework.getLogger(CLASS_NAME).logrb(
                Level.FINEST,
                CLASS_NAME.getName(),
                "handleProcessReply",
                JmsConstants.JMS_LOG_RESOURCE_BUNDLE,
                "UIMAJMS_timer_detail_FINEST",
                new Object[] { message.getStringProperty(AsynchAEMessage.MessageFrom),
                    "Total Time In Process CAS", (float) totaltimeInProcessCAS / (float) 1000000 });
      }
      float timeInMillis = (float) totaltimeInProcessCAS / (float) 1000000;
      pt.addEvent("UimaEE", "process", "Total Time In Process CAS", (int) timeInMillis, "");
      clientSideJmxStats.incrementTotalTimeToProcess(totaltimeInProcessCAS);
    }
    if (message.propertyExists(AsynchAEMessage.IdleTime)) {
      long totalIdletime = message.getLongProperty(AsynchAEMessage.IdleTime);
      if (UIMAFramework.getLogger(CLASS_NAME).isLoggable(Level.FINEST)) {
        UIMAFramework.getLogger(CLASS_NAME).logrb(
                Level.FINEST,
                CLASS_NAME.getName(),
                "handleProcessReply",
                JmsConstants.JMS_LOG_RESOURCE_BUNDLE,
                "UIMAJMS_timer_detail_FINEST",
                new Object[] { message.getStringProperty(AsynchAEMessage.MessageFrom),
                    "Idle Time Waiting For CAS", (float) totalIdletime / (float) 1000000 });
      }
      pt.addEvent("UimaEE", "process", "Idle Time Waiting For CAS",
              (int) (totalIdletime / 1000000), "");
      clientSideJmxStats.incrementTotalIdleTime(totalIdletime);
    }
    if (message.propertyExists(AsynchAEMessage.ServerIP)) {
      pt.addEvent("UimaEE", "process", "Service IP", 0, message
              .getStringProperty(AsynchAEMessage.ServerIP));
    }

  }