Geoprocessing Service Runs But Doesn't Produce Output

[LloydBronn]

So I've created a geoprocessing Python script tool that I've published as a GP service. This script takes lat/lon coordinates, extracts data from a raster from these coordinates, outputs a .csv and creates an Excel chart from a .vbs script. I can run the Python script on our server from the "C:\arcgisserver\directories\arcgissystem\arcgisinput" path and it works. I'm trying to test the GP service (Execute Task (GET))  from a browser on our REST services page. It says it's successful, but it doesn't actually output the chart. It does create the .csv, but it doesn't run the .vbs script. Here is the result message:

{
 "results": [],
 "messages": [
  {
   "type": "esriJobMessageTypeInformative",
   "description": "Executing (ChartTest): ChartTest 45 -122 Portland"
  },
  {
   "type": "esriJobMessageTypeInformative",
   "description": "Start Time: Wed Jan 25 13:51:23 2017"
  },
  {
   "type": "esriJobMessageTypeInformative",
   "description": "Executing (ChartTest): ChartTest 45 -122 Portland"
  },
  {
   "type": "esriJobMessageTypeInformative",
   "description": "Start Time: Wed Jan 25 13:51:23 2017"
  },
  {
   "type": "esriJobMessageTypeInformative",
   "description": "Running script ChartTest..."
  },
  {
   "type": "esriJobMessageTypeInformative",
   "description": "Completed script ChartTest..."
  },
  {
   "type": "esriJobMessageTypeInformative",
   "description": "Succeeded at Wed Jan 25 13:51:23 2017 (Elapsed Time: 0.70 seconds)"
  },
  {
   "type": "esriJobMessageTypeInformative",
   "description": "Succeeded at Wed Jan 25 13:51:23 2017 (Elapsed Time: 0.71 seconds)"
  }
 ]
}‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

I had a lot of trouble publishing this GP service because the Python script creates a .vbs, and these types of scripts can't be copied to the server. I got around this by changing the ".vbs" reference to ".txt" and publishing. I changed it back to ".vbs" on the server. I'm not sure if the server is blocking the .vbs or what. There are no errors in the server logs. 

[LloydBronn]

I set the workspace and added a print statement, but the execute task page just returned the same results as above. Still no chart or .vbs script created. 

arcpy.env.scratchWorkspace = "C:\arcgisserver\directories\arcgisjobs\scratch"


try: 
   os.system(raster_vbs_script_filepath)
 except:
    arcpy.AddMessage("Failed to create .vbs file.")‍‍‍‍‍‍‍

[JonathanQuinn]

The arcpy.env.scratchFolder environment variable is set for you when you run the GP service.  There's no need to set it to anything within your script.  Simply construct the path to your output data using the arcpy.env.scratchFolder environment variable:

vbs_filepath = os.path.join(arcpy.env.scratchFolder,"Build_raster_Charts.vbs")

Do you see your "Failed to create .vbs file" message?  Is there anything in the server logs?  Try to set the logs to DEBUG.

[LloydBronn]

We did some digging last night and discovered that the script is stopping before it even opens Excel, after the csv is created. So it wasn't even getting to the vbs script. It stops at this line in the Python script. 

Excel = xlApp.Workbooks.Open(spreadsheet_template_filepath)‍

I tried setting all the Excel files and vbs script to output paths to os.path.join(arcpy.env.scratchFolder,"file.xlsm") It DID work in IDLE when these paths are joined to the scratchFolder.

I also changed the paths for the Excel spreadsheet and vbs script to our wwwroot folder that's accessible from our web server. And I moved the Excel and vbs files to "C:\arcgisserver\directories\arcgissystem\arcgisinput\Excel_Files" .This didn't work either. 

The crazy thing is, there is nothing in the server logs. No errors, or any messages at all. And no matter what we do, the execute task page returns the same message that the script ran successfully. 

I found this thread, and I'm wondering if we need to add the Windows Script Host to the application pool on the IIS server?

When I open the registry editor, there is no "enable" key under the Windows Script Host settings. 

[JonathanQuinn]

If the Excel file isn't generated, then we should focus on that first before looking into running the .vbs script.  What version are you using?  If you're creating an .xls file, what if you use arcpy instead?  I'm not sure if you use your other module due to a formatting thing.

What is the spreadsheet_template_filepath variable set to?  I imagine the GP service would fail if Server couldn't access the file.  Can you add a message for the Excel variable and see what it returns, (arcpy.AddMessage(Excel).  It may not be the actual data but at least you can verify if it's opening the template Excel file or not.  I wouldn't move anything within wwwroot, because then you introduce latency going through your web server.

[LloydBronn]

We're using Excel 2016 on the server. 

The spreadsheet template variable is:

vbs_filepath = os.path.join(arcpy.env.scratchFolder,"Build_" + custom_suffix + "Charts.vbs")‍‍‍‍

It writes successfully to the server scratch folder when I run it in IDLE. 

Here is the module that creates the spreadsheet from the csv. It uses a static Excel template "CFS_Monthly_chart_template.xlsm", which I've placed in the scratch folder. I put in print statements to confirm the location of the scratch folder. It's: "C:\arcgisserver\directories\arcgissystem\arcgisinput\Chart_Test.GPServer\extracted\v101\website_test\scratch"

We created a log file output in the Python script to try to find out where the error is. It prints to line #22 here and then prints the error message at line #65, so we verified that it's not even opening Excel from the Server. 

def build_spreadsheet_for_charts(location_data_dict,chart_folder,custom_suffix,daily_analysis_tablename,data_source):

    ##chart_test_path = "C:\\Chart_Test"
    chart_test_path = r_chart_path

    foldername = chart_folder

    ##r_spreadsheet_filepath = chart_test_path + "\\" + "CFS_Charts.xlsm"
    r_spreadsheet_filepath = os.path.join(arcpy.env.scratchFolder,"CFS_Charts.xlsm")
    ##r_spreadsheet_filepath = excel_files_path + "\\" + "CFS_Charts.xlsm"

    ##spreadsheet_template_filepath = chart_test_path + "\\" + "CFS_Monthly_chart_template.xlsm"
    ##spreadsheet_template_filepath = "C:\\Chart_Test\\CFS_Monthly_chart_template.xlsm"
    spreadsheet_template_filepath = os.path.join(arcpy.env.scratchFolder,"CFS_Monthly_chart_template.xlsm")   

    xlApp = None
    try:
        xlApp = win32com.client.Dispatch("Excel.Application")
        
        xlApp.Visible = False

        output_log_file.write("Getting ready to open excel spreadsheeet template \n")

        Excel = xlApp.Workbooks.Open(spreadsheet_template_filepath)

        output_log_file.write("Successfully opened excel spreadsheeet template \n")

        location_label = ""
        
        starting_row = 2
        row = starting_row
        ## index for location_data_dict starts at 1 not 0 (dictionary uses input index not standard index for a list)
        for location_index in range(1,len(location_data_dict)+1):
            location_data_tuple = location_data_dict[location_index]

            country, name, lat_str, lon_str, wmo_str, elev_m_str = location_data_tuple
            
            if location_index > 1:  ## location index = 1  --> row = 5; location index = 2 --> row = 6 (not 7)
                row = starting_row + (location_index - 1)
                    
            Excel.Worksheets("Available_Stations").Range("A" + str(row)).Formula = wmo_str
            Excel.Worksheets("Available_Stations").Range("B" + str(row)).Formula = lat_str
            Excel.Worksheets("Available_Stations").Range("C" + str(row)).Formula = lon_str
            Excel.Worksheets("Available_Stations").Range("D" + str(row)).Formula = name  
            Excel.Worksheets("Available_Stations").Range("E" + str(row)).Formula = country
            Excel.Worksheets("Available_Stations").Range("F" + str(row)).Formula = elev_m_str
            
        Excel.Worksheets("Available_Stations").Range("J2").Formula = foldername
        Excel.Worksheets("Available_Stations").Range("L2").Formula = data_source

        ## End of Location For Loop
        print r_spreadsheet_filepath
        if exists(r_spreadsheet_filepath):
            os.remove(r_spreadsheet_filepath)
        
        xlApp.ActiveWorkbook.SaveAs(r_spreadsheet_filepath)

        xlApp.ActiveWorkbook.Close
        xlApp.Quit()

        del xlApp
    except:
        output_log_file.write("Error updating CFS Charts spreadsheet from template\n")
        output_log_file.close()
        print "Error updating CFS Charts spreadsheet from template"
        del xlApp
        sys.exit()

    return()‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

[JonathanQuinn]

You should print the traceback error, as there's no way to know why it failed if it's in your try: except block.  Can you update line 65 to:

print "Error updating CFS Charts spreadsheet from template\n{0}".format(traceback.format_exc())

You can parse out the traceback error however you like, but it's important to return it.  In this case, it may be best to remove the try: except block so you can return all of the messages within the GP service framework.  Be sure to import the traceback module at the beginning of your script.

[LloydBronn]

I added this line, but I didn't get an error message. Yesterday I added our ArcGIS server user login to the DCOM registry for Excel, and to the Desktop folder permissions under the Windows system folders (32 and 64 bit). Now when I click execute task on the REST page, a log file is generated on the server. It claims that that whole process is completing. This is new. However, nothing is generated in the scratch folder on the server. It still runs perfectly in IDLE. 

Here is the log file output. It never got past line 3 here before. This log file is identical, whether I  run the script from IDLE or from the REST page.  

1. starting to create csv data file
2. starting to build the spreadsheet
3. Getting ready to open excel spreadsheeet template
4. Successfully opened excel spreadsheeet template
5. starting to build vbs script
6. starting to execute vbs script
7. return value: 0 commandline_output:

I'm wondering if I have my scratch workspace set correctly? It's 

arcpy.env.scratchWorkspace = "C:\arcgisserver\directories\arcgisjobs"

The scratch folder is under the arcgissystem\arcgisinputs folder.

I'm also wondering about the data store on the server. I shouldn't have to register the scratch folder should I?

[JonathanQuinn]

Ahh, sorry, Lloyd, I meant to update it to arcpy.AddMessage(<message>).  You'll never see print statements when running a GP tool or GP service.  If you still have your try: except block, remote that and let errors come back directly through the GP service.

You don't need to set any scratch workspaces, folders or geodatabases.  The default path for them is correct.  For ease of use, simply use the default of arcpy.env.scratchFolder to construct the path to output data that exists in folders.

The scratch folder doesn't need to be registered on the Server, as it knows it can write to the directory already, (providing it's left at the default location).  I wouldn't think that the raster data location is a problem, as it would fail earlier in the script.

[LloydBronn]

OK, I moved all of my data back to the server folders they were originally extracted to when I published the GP service. I had commented out all the g_ESRI_variables and put everything in local folders to test it in IDLE. I reinstated these paths.

When I try to run the script in IDLE now, I get this, "Error finding C:\Users\ADMINI~1.MET\AppData\Local\Temp\2"

 I added this at the start of the script to see what was going on:

scratch_folder = arcpy.env.scratchFolder

print(scratch_folder)

sys.exit()‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

If I don't define the scratch workspace, it prints this:

C:\Users\ADMINI~1.MET\AppData\Local\Temp\2\scratch

If I set the workspace to arcpy.env.scratchWorkspace = "C:\arcgisserver\directories\arcgisjobs", it prints this:

C:\arcgisserver\directories\arcgissystem\arcgisinput\Chart_Test.GPServer\extracted\v101\website_test\scratch

When I first published the tool, it was set to g_ESRI_variable_1 = os.path.join(arcpy.env.packageWorkspace,u'temp'). When I set it back to this, it also prints:

C:\Users\ADMINI~1.MET\AppData\Local\Temp\2\scratch

So I'm confused. There seem to be two scratch folders,

Scratch Workspace: C: rcgisserver\directories rcgisjobs\scratch
Scratch Folder: C:\arcgisserver\directories\arcgissystem\arcgisinput\Chart_Test.GPServer\extracted\v101\website_test\scratch
‍‍

[JonathanQuinn]

Is this a single machine site or a multi-machine site?  ArcGIS Server would only use local jobs directories, (the local\temp directory), in multi-machine sites.  If it's a single machine, I'm surprised you're not seeing the path pointing to the arcgisjobs directory.  Does the C:\Users\ADMINI~1.MET\AppData\Local\Temp\2 path exist?  If you revert those changes to allow the service to run, do you still have the try: except block capturing the failure?  It's important to allow the gp service to return it's own errors, or raise an exception within the except block instead of just printing a message.