Uploaded image for project: 'HPCC'
  1. HPCC
  2. HPCC-23899

Roxie log COMPLETE message could better represent time spent in Soapcall when exceptions occur

    Details

    • Type: Improvement
    • Status: Resolved
    • Priority: Not specified
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 7.6.42
    • Component/s: Roxie
    • Labels:
      None

      Description

      It appears that if a Soapcall is made by a Roxie query, and the Soapcall times out and gets an exception, none of the time spent in the failed Soapcall is represented in TimeSoapcall metric.

      For example:

      0005B72F 2020-04-20 22:27:20.329 3652 4264 "[10.194.174.15:9876

      {F2e7tmu7y8GWcfDszbNQBY}

      [caller:F2e7tn2ZXNzgGWxoVr7yDu,local:F2e7tpK8pGUcLJBjSVfYVN]] COMPLETE: NCF_Services.Service_ProcessBureaus F2e7tmu7y8GWcfDszbNQBY[caller: F2e7tn2ZXNzgGWxoVr7yDu, local: F2e7tpK8pGUcLJBjSVfYVN] from 127.0.0.1 complete in 16320 msecs memory=41 Mb priority=-2 slavesreply=0 resultsize=15183 continue=0 WhenFirstRow=2020-04-21T02:27:04.032Z TimeElapsed=5m10.441s TimeTotalExecute=1m49.212s NumIndexSeeks=10 NumIndexWildSeeks=9 NumLeafCacheHits=7 NumIndexAccepted=1 TimeSoapcall=611.627ms TimeFirstExecute=1m49.193s TimeSortElapsed=234ns TimeLocalExecute=15.707s NumAllocations=11083984 fgetGlobalId=

      { NumStarts=1 NumStops=1 TimeLocalExecute=1.711us }

      fgetLocalId=

      { NumStarts=1 NumStops=1 TimeLocalExecute=338ns }

      fgetCallerId=

      { NumStarts=1 NumStops=1 TimeLocalExecute=313ns }

      "

      In this case, there was a Soapcall to an external vendor that had a TIMEOUT(15) that eventually failed and accounted for the overwhelming majority of time spent in the query, but TimeSoapcall only shows the 611.627ms that were spent in the successful Soapcalls.

      At a minimum, it would be good if the TimeSoapcall metric included the time spent in failed Soapcalls; perhaps it would be even better if there were a separate metric that accounted for this time.

      Gavin HallidayAnthony Fishbeck Mark Chambers

        Attachments

          Activity

            People

            • Assignee:
              richardkchapman Richard Chapman
              Reporter:
              kev77log Kevin Logemann
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: