AnsweredAssumed Answered

GPServerSync.Load execution delay

Question asked by IanHoganNAU on Jan 21, 2015
Latest reply on Jan 27, 2015 by IanHoganNAU

Hi,

 

Long story short, does anyone know how to debug, or have any insight, into GPServerSync calls?

 

I have a Python Geoprocessing Service I've published on ArcGIS Server 10.2. It's pretty basic; it takes a zipfile that's been uploaded already which contains a shapefile, it dissolves that shapefile, repairs the geometry, and then it returns a feature dataset.

 

Executing this in ArcMap on my laptop takes about 600 milliseconds.

 

In ArcGIS Server, it executes, but it takes about 7 minutes.

 

I modified the service to output to my own logfile to see if there was a specific python call that was causing the delay, but it appears that once the script is actually executed, it really only takes a second. The issue is that there appears to be a several minutes long delay between when the job is submitted and when the script is actually run.

 

ArcGIS Server verbose logs shows this. The request is issued at 10:43:30. 2 seconds later, there's an entry for GPServerSync.InitJob. The next logged item is GPServerSync.Load, which doesn't occur until 10:49:57, which is 6 and a half minutes later.

 

The script then executes in less than a second.

 

Any ideas?

 

Ian

 

 

<Msg time='2015-01-21T10:43:30,790' type='VERBOSE' code='20025' target='DebugDissolveRepairGP.GPServer' methodName='GPServerSync.Activate' machine='myserver' process='13868' thread='14080' user='anonymous' elapsed='0.00002'>GPServerSync.Activate</Msg>

<Msg time='2015-01-21T10:43:30,791' type='FINE' code='100001' target='DebugDissolveRepairGP.GPServer' methodName='tasks/Dissolve Repair GP debug/execute' machine='myserver' process='13868' thread='14080' user='anonymous' >REST request received. Request size is 99 characters.</Msg>

<Msg time='2015-01-21T10:43:32,121' type='VERBOSE' code='20023' target='DebugDissolveRepairGP.GPServer' methodName='GPServerSync.LoadMessage.Dissolve Repair GP debug' machine='myserver' process='13868' thread='14080' user='anonymous' elapsed='1.33086'>Load job  message type REST message size 99</Msg>

<Msg time='2015-01-21T10:43:32,474' type='VERBOSE' code='20025' target='DebugDissolveRepairGP.GPServer' methodName='GPServerSync.InitJob.Dissolve Repair GP debug' machine='myserver' process='13868' thread='14080' user='anonymous' elapsed='0.35291'>Load job j3e3c698147734869b66d0d87cdf1f3a4 message type REST message size 99</Msg>

<Msg time='2015-01-21T10:49:57,920' type='VERBOSE' code='20023' target='DebugDissolveRepairGP.GPServer' methodName='GPServerSync.Load.Dissolve Repair GP debug' machine='myserver' process='13868' thread='14080' user='anonymous' elapsed='385.44774'>Load job j3e3c698147734869b66d0d87cdf1f3a4 message type REST message size 99</Msg>

<Msg time='2015-01-21T10:49:58,566' type='VERBOSE' code='20022' target='DebugDissolveRepairGP.GPServer' methodName='GPServerSync.Execute.Dissolve Repair GP debug' machine='myserver' process='13868' thread='14080' user='anonymous' elapsed='0.64588'>Execute job j3e3c698147734869b66d0d87cdf1f3a4</Msg>

<Msg time='2015-01-21T10:49:58,612' type='VERBOSE' code='20024' target='DebugDissolveRepairGP.GPServer' methodName='GPServerSync.Save.Dissolve Repair GP debug' machine='myserver' process='13868' thread='14080' user='anonymous' elapsed='0.04564'>Save job j3e3c698147734869b66d0d87cdf1f3a4 message type REST message size 99</Msg>

<Msg time='2015-01-21T10:49:58,612' type='FINE' code='100004' target='DebugDissolveRepairGP.GPServer' methodName='tasks/Dissolve Repair GP debug/execute' machine='myserver process='13868' thread='14080' user='anonymous' elapsed='387.82342'>REST request successfully processed. Response size is 82880 characters.</Msg>

<Msg time='2015-01-21T10:49:58,618' type='VERBOSE' code='20025' target='DebugDissolveRepairGP.GPServer' methodName='GPServerSync.Deactivate' machine='myserver' process='13868' thread='14080' user='anonymous' elapsed='0.00606'>GPServerSync.Deactivate</Msg>

Outcomes