Question

Running arcpy in PythonCaller and shutdown script

lottegis
Badge +1

I have a workspace with a FileGDB where I'm removing and adding attribute indexes with the help of arcpy. I also use FMELogFile for logging. FME Desktop does not have a problem with the translation, but the warning messages and job failure occur once I publish to FME Server. I'm having an issue with a
workspace with the following log messages:

WARN|Warning: not all FMESessions that were created were destroyed before shutdown. This may cause instability
WARN|Warning: not all Stashed Objects that were registered were dropped before
shutdown. This may cause instability

and maybe this one is related:

INFORM|Optional `close' method not present; not called

Please see:

  • cadastral_to_gdb_update.fmw
  • cadastral_to_gdb_update.log - Desktop
  • cadastral_to_gdb_update_job_11563.log - Server
  • ALTTRANS01_fmeserver_2018-01-22_job11563.log - Server Engine

I have a simplified test workspace that uses arcpy to run Exists() and a logger. This one runs just fine on FME Server. Please see:

  • check_arcpy.fmw
  • check_arcpy.log - Desktop
  • check_arcpy_job_11226.log - Server

Thank you.

1 Attachment

11 replies

takashi
Rank
Userlevel 2
Badge +17

Hi @lottegis, The "cadastral_to_gdb_update.log" (Desktop) contains logs for several translations, and all translations seems to have failed with a bug in Python script, except the last one in 2018-01-23 14:00+. On the other hand, the date of log messages within "cadastral_to_gdb_update_job_11563.log" (Server) is 2018-01-22 17:00+. I'm not sure if the log from Server was generated with the latest workspace (2018-01-23 14:00+) which doesn't have the bug.

What happens if you republish the latest workspace to Server?

david_r
Rank
Userlevel 4

Referring to check_arcpy.fmw, there's an instance of fmeobjects.FMELogFile() instantiated in the startup script which causes the warning message at the end of translation. You can safely ignore this warning as it's nothing serious, or you can add the following line at the very end of your shutdown script:

del logger

This frees up the FMELogFile instance and avoids the warning message.

lottegis
Badge +1

Hi @lottegis, The "cadastral_to_gdb_update.log" (Desktop) contains logs for several translations, and all translations seems to have failed with a bug in Python script, except the last one in 2018-01-23 14:00+. On the other hand, the date of log messages within "cadastral_to_gdb_update_job_11563.log" (Server) is 2018-01-22 17:00+. I'm not sure if the log from Server was generated with the latest workspace (2018-01-23 14:00+) which doesn't have the bug.

What happens if you republish the latest workspace to Server?

Sorry Takashi... The package was originally meant for live chat support but obviously I've made changes to the workspaces since then. I'm attaching an updated set of logs. As you'll see, I no longer get the warning notices, but the job still ends in failure after 3 retries.

 

 

gdb-update-arcpy-2.zip:

 

  • check_arcpy_job_12107.log - Server
  • cadastral_to_gdb_update_job_12108.log - Server, final log after 3 retry attempts
  • cadastral_to_gdb_update_job_12108_attempt2.log - Server, during the 2nd retry
  • ALTTRANS01_fmeserver_job12107-12108.log - Server, both jobs for check_arcpy and update
  • cadastral_to_gdb_update.log - Desktop

 

From the server job log, does this raise any flags?

 

INFORM|An ArcGIS license is already checked out. The product checked out is 'ArcServer'<br>INFORM|Installed ArcGIS version is '?.?'
I also tried restarting ArcGIS Server service. Same result.

 

 

david_r
Rank
Userlevel 4
Sorry Takashi... The package was originally meant for live chat support but obviously I've made changes to the workspaces since then. I'm attaching an updated set of logs. As you'll see, I no longer get the warning notices, but the job still ends in failure after 3 retries.

 

 

gdb-update-arcpy-2.zip:

 

  • check_arcpy_job_12107.log - Server
  • cadastral_to_gdb_update_job_12108.log - Server, final log after 3 retry attempts
  • cadastral_to_gdb_update_job_12108_attempt2.log - Server, during the 2nd retry
  • ALTTRANS01_fmeserver_job12107-12108.log - Server, both jobs for check_arcpy and update
  • cadastral_to_gdb_update.log - Desktop

 

From the server job log, does this raise any flags?

 

INFORM|An ArcGIS license is already checked out. The product checked out is 'ArcServer'<br>INFORM|Installed ArcGIS version is '?.?'
I also tried restarting ArcGIS Server service. Same result.

 

 

That server log entry looks perfectly normal to me.
lottegis
Badge +1
That server log entry looks perfectly normal to me.
Do you mean the job log? If so, the translation never ended and it was stuck at "Optional `close' method not present; not called". This means data went through deletion but never through insertion.

 

 

If you meant the engine log, the translation itself and its subsequent 3 retries end in fatal error. That is not normal...
david_r
Rank
Userlevel 4
Do you mean the job log? If so, the translation never ended and it was stuck at "Optional `close' method not present; not called". This means data went through deletion but never through insertion.

 

 

If you meant the engine log, the translation itself and its subsequent 3 retries end in fatal error. That is not normal...
I mean this bit you posted above from the job log:

 

INFORM|An ArcGIS license is already checked out. The product checked out is 'ArcServer'<br>INFORM|Installed ArcGIS version is '?.?'
That's normal.

 

david_r
Rank
Userlevel 4

I see in the cadastral_to_gdb_update workspace that you do some stuff with the Python path in the startup script. Are your sure that's not part of the issue? Or more specifically, what are you trying to fix with those modifications?

Weird things can happen with arcpy if the Python path isn't 100% correct.

lottegis
Badge +1
Do you mean the job log? If so, the translation never ended and it was stuck at "Optional `close' method not present; not called". This means data went through deletion but never through insertion.

 

 

If you meant the engine log, the translation itself and its subsequent 3 retries end in fatal error. That is not normal...
Thanks for clarifying!
lottegis
Badge +1

I see in the cadastral_to_gdb_update workspace that you do some stuff with the Python path in the startup script. Are your sure that's not part of the issue? Or more specifically, what are you trying to fix with those modifications?

Weird things can happen with arcpy if the Python path isn't 100% correct.

There are two areas where I require Python - PythonCaller in mid-workspace and in the Shutdown script. I was getting issues with how FME was not able to close out the translation properly. I put the import and global init stuff there so it's done once as a way to mitigate that. The sys imports are for pointing FME Server to where the arcpy modules are. The check_arcpy.fmw workspace also has this and it runs successfully...

 

lottegis
Badge +1
I'm uploading a third attachment. This is of the update workspace without arcpy in place that works on the Server.

 

  • cadastral_to_gdb_update_wo_arcpy.fmw - Published to Server as "cadastral_to_gdb_update.fmw" so the logs reflect as such
  • cadastral_to_gdb_update_wo_arcpy_job_12105.log - Server
  • ALTTRANS01_fmeserver_job12105.log - Server Engine
lottegis
Badge +1

From Safe Support:

"The crash should only really be present when arcpy and a database connection (or an FME Web Connection it seems, unfortunately) are in the same workspace. This only happens when FME uses ArcGIS Server version of arcpy (not ArcGIS Desktop).

"We've further investigated and it seems like this problem is present in two different ways. The first is the one which you and I have seen - which is where arcpy is used first, followed by a Database (or web) connection. This is where we see the crash followed by the java memory dump. The second crash is when a Database (or web) connection is used first, followed by arcpy. In this crash there is no memory dump, just a crash of the process. This would be the type of crash seen if the arcpy was only in a shutdown script as the python will always be last.

"In regards to your question about the SystemCaller - The SytemCaller will create a separate thread/process so there shouldn't be a crash."

Track issue PR#79353

Reply


Community Stats

28,670
Posts
109,365
Replies
36,531
Members
Terms & ConditionsCookie settings
A product of
Safe Software respectfully acknowledges that we live, learn and work on the traditional and unceded territories of the Kwantlen, Katzie, and Semiahmoo First Nations.