Skip to main content
Solved

deployed Batch runs very slow as scheduled task

reservoirdog
Supporter
Forum|alt.badge.img+10

Hello community!

 

 

I have 7 Batches (created via Batch deploy), that read spatial data from an oracle 10 database into SQLite. The biggest user takes, when batch is started manually, about 18 minutes. When this batch is started using windows scheduler, it takes up to 3 hours! Same for all the others. 

 

I'm using FME 2013 SP1 Oracle Edition on Windows Server 2012.

 

neither the oracle server nor the fme server is under heavy load. (1-5% cpu).

 

scheduled task are started as same user which starts manually the batches.

 

(admin, highest privileges). Is there an option to tell each task its priority?

 

is there a problem when batchfiles and tclfiles are located on desktop?

 

(workspace are located in user\\documents\\my fme workspaces)

 

 

would be thankful for any advice.

 

best regards, chris.

Best answer by david_r

Hi,

 

 

It is possible that you need to adjust an additional parameter for the scheduled task, as they might run with a lower than normal memory priority on some Windows versions (this is not the same as the process priority).

 

 

Take a look at the answer to the related question here. It might be what you're looking for.

 

 

Please let us know if it solves the problem.

 

 

David
View original
Did this help you find an answer to your question?
This post is closed to further activity.
It may be a question with a best answer, an implemented idea, or just a post needing no comment.
If you have a follow-up or related question, please post a new question or idea.
If there is a genuine update to be made, please contact us and request that the post is reopened.

6 replies

david_r
Evangelist
  • david_rEvangelist
  • April 25, 2013
Hi Chris,

 

 

you might want to compare the log files from the scheduled run and the manual execution. The timestamps ought to give you an indication of where the time is spent. That would be a good first step, anyway.

 

 

David
reservoirdog
Supporter
Forum|alt.badge.img+10
  • reservoirdogSupporter
  • Author
  • Supporter
  • April 25, 2013
Hey David, thx for your answer!

 

 

I did that already, and all i could see was, that when scheduled, 

 

fme reads feature sources much slower compared to manually started.

 

 

see following cutout of one "manually started batch":

 

2013-04-24 11:18:11| 11.8| 0.0|INFORM|Creating FdoFeatureClass 'Default:GA_V_DSP_PIPE_TBL'

 

2013-04-24 11:18:12| 12.0| 0.2|INFORM|Reading source feature # 15000

 

2013-04-24 11:18:18| 13.9| 2.0|INFORM|Reading source feature # 17500

 

2013-04-24 11:18:24| 15.8| 1.9|INFORM|Reading source feature # 20000

 

2013-04-24 11:18:30| 17.8| 2.0|INFORM|Reading source feature # 22500

 

2013-04-24 11:18:36| 19.7| 1.8|INFORM|Reading source feature # 25000

 

2013-04-24 11:18:39| 20.7| 1.0|INFORM|ORACLE Reader: Executing SQL Statement `SELECT "GA_V_DSP_PIPE"."FID", "GA_V_DSP_PIPE"."FID_ATTR", "GA_V_DSP_PIPE"."ID_FUNCTION", "GA_V_DSP_PIPE"."COLOR_RGB", "GA_V_DSP_PIPE"."PRESS_NARRATIVE", "GA_V_DSP_PIPE"."ID_DISPOSITION_STATE", "GA_V_DSP_PIPE"."ID_ACCURACY", "GA_V_DSP_PIPE"."DATUM", "GA_V_DSP_PIPE"."DIAMETER_INSIDE", "GA_V_DSP_PIPE"."DIAMETER_OUTSIDE", "GA_V_DSP_PIPE"."DIAMETER_NOMINAL", "GA_V_DSP_PIPE"."GEOM" FROM "GA_V_DSP_PIPE"' to obtain features for feature type `GA_V_DSP_PIPE'

 

2013-04-24 11:18:39| 20.7| 0.0|INFORM|Creating FdoFeatureClass 'Default:GA_V_DSP_PIPE'

 

2013-04-24 11:18:43| 21.7| 0.9|INFORM|Reading source feature # 27500

 

2013-04-24 11:18:49| 23.7| 2.1|INFORM|Reading source feature # 30000

 

2013-04-24 11:18:56| 25.9| 2.2|INFORM|Reading source feature # 32500

 

2013-04-24 11:19:02| 27.8| 1.9|INFORM|Reading source feature # 35000

 

2013-04-24 11:19:08| 30.0| 2.1|INFORM|Reading source feature # 37500

 

2013-04-24 11:19:15| 31.9| 2.0|INFORM|Reading source feature # 40000

 

2013-04-24 11:19:21| 34.0| 2.1|INFORM|Reading source feature # 42500

 

 

2013-04-24 11:26:02| 153.9| 0.0|INFORM|Translation was SUCCESSFUL with 20 warning(s) (202635 feature(s) output)

 

2013-04-24 11:26:02| 153.9| 0.0|INFORM|FME Session Duration: 8 minutes 37.6 seconds. (CPU: 94.1s user, 59.7s system)

 

2013-04-24 11:26:02| 153.9| 0.0|INFORM|END - ProcessID: 3748, peak process memory usage: 100876 kB, current process memory usage: 83580 kB

 

 

And now the cutout of the same batch, started via scheduler:

 

2013-04-24 17:17:02| 2.2| 0.0|INFORM|Creating FdoFeatureClass 'Default:GA_V_DSP_PIPE_TBL'

 

2013-04-24 17:17:18| 2.2| 0.0|INFORM|Reading source feature # 15000

 

2013-04-24 17:20:09| 2.3| 0.1|INFORM|Reading source feature # 17500

 

2013-04-24 17:22:51| 2.4| 0.1|INFORM|Reading source feature # 20000

 

2013-04-24 17:25:32| 2.4| 0.1|INFORM|Reading source feature # 22500

 

2013-04-24 17:28:15| 2.6| 0.1|INFORM|Reading source feature # 25000

 

2013-04-24 17:29:30| 2.6| 0.0|INFORM|ORACLE Reader: Executing SQL Statement `SELECT "GA_V_DSP_PIPE"."FID", "GA_V_DSP_PIPE"."FID_ATTR", "GA_V_DSP_PIPE"."ID_FUNCTION", "GA_V_DSP_PIPE"."COLOR_RGB", "GA_V_DSP_PIPE"."PRESS_NARRATIVE", "GA_V_DSP_PIPE"."ID_DISPOSITION_STATE", "GA_V_DSP_PIPE"."ID_ACCURACY", "GA_V_DSP_PIPE"."DATUM", "GA_V_DSP_PIPE"."DIAMETER_INSIDE", "GA_V_DSP_PIPE"."DIAMETER_OUTSIDE", "GA_V_DSP_PIPE"."DIAMETER_NOMINAL", "GA_V_DSP_PIPE"."GEOM" FROM "GA_V_DSP_PIPE"' to obtain features for feature type `GA_V_DSP_PIPE'

 

2013-04-24 17:29:30| 2.6| 0.0|INFORM|Creating FdoFeatureClass 'Default:GA_V_DSP_PIPE'

 

2013-04-24 17:30:57| 2.7| 0.1|INFORM|Reading source feature # 27500

 

2013-04-24 17:33:38| 2.9| 0.2|INFORM|Reading source feature # 30000

 

2013-04-24 17:36:19| 3.1| 0.2|INFORM|Reading source feature # 32500

 

2013-04-24 17:39:00| 3.2| 0.2|INFORM|Reading source feature # 35000

 

2013-04-24 17:41:41| 3.5| 0.2|INFORM|Reading source feature # 37500

 

2013-04-24 17:45:20| 3.8| 0.4|INFORM|Reading source feature # 40000

 

2013-04-24 17:48:45| 4.2| 0.4|INFORM|Reading source feature # 42500

 

 

2013-04-24 21:16:07| 12.3| 0.0|INFORM|Translation was SUCCESSFUL with 20 warning(s) (202635 feature(s) output)

 

2013-04-24 21:16:07| 12.3| 0.0|INFORM|FME Session Duration: 4 hours 15 minutes 52.8 seconds. (CPU: 9.4s user, 2.8s system)

 

2013-04-24 21:16:07| 12.3| 0.0|INFORM|END - ProcessID: 2720, peak process memory usage: 101896 kB, current process memory usage: 83572 kB
david_r
Evangelist
  • david_rEvangelist
  • Best Answer
  • April 25, 2013
Hi,

 

 

It is possible that you need to adjust an additional parameter for the scheduled task, as they might run with a lower than normal memory priority on some Windows versions (this is not the same as the process priority).

 

 

Take a look at the answer to the related question here. It might be what you're looking for.

 

 

Please let us know if it solves the problem.

 

 

David
fmelizard
Contributor
Forum|alt.badge.img+17
  • fmelizardContributor
  • Contributor
  • April 25, 2013
Hi,

 

 

Another option would be to use this software, (prio) to allocate a higher taskng priority to the job.

 

Hope this helps
mark2atsafe
Safer
Forum|alt.badge.img+43
  • mark2atsafeSafer
  • Safer
  • April 25, 2013
Hi Chris,

 

As a matter of interest I looked at your log and saw:

 

 

2013-04-24 17:17:18| 2.2| 0.0|INFORM|Reading source feature # 15000

 

2013-04-24 17:20:09| 2.3| 0.1|INFORM|Reading source feature # 17500

 

 

There you have a step that takes nearly 3 minutes (17:17:18 - 17:20:09) but the FME processing time is only 0.1 seconds (3rd column). So I think that whatever the slowdown is, it is not related to the FME engine, as such.

 

 

But is it related to reading data? It's hard to tell from the log what exactly is going on at any one point. Although that steps says "Reading" it could also be doing transformation (if there is any) and even writing.

 

 

The only way to be sure would be to put a FeatureHolder transformer after the reader. Then transformation/writing won't start until after the reading is done. If you try this and the numbers improve for that section then you can tell the slowdown is not in reading. That might help diagnose the problem.

 

 

Anyway, you said that the machines aren't under a heavy load so I can't imagine why the priority would make such a difference (if there were a hundred other processes I could understand it). The system CPU time being logged is negligable too and the peak memory usage doesn't look that high, so I'm baffled as to why the system would be slower.

 

 

Besides that I suppose there is database response and network traffic. Is there a way to log queries in the database to see how long they take? I'd be interested to know if the queries are taking longer somehow. I somehow see that as being more likely than network slowdowns.

 

 

What about temporary disk space etc? Can you post the top part of the logs too, to compare the two sections? To see if the machine specs/memory use is being handled differently?

 

 

Hope this is of some use

 

 

Mark
reservoirdog
Supporter
Forum|alt.badge.img+10
  • reservoirdogSupporter
  • Author
  • Supporter
  • April 26, 2013
Thank you all for your answers!

 

David was right, assuming lower priorities using task scheduler.

 

as default, when a process is manually started, it runs in realtime (priority = 0).

 

when using task scheduler, processes are started with priority = 7. In my case, this caused the fme worker to read very slow. 

 

With the import/export method highlighted by David, it worked now.

 

Same processing time like manually started.

 

 

THANK YOU GUYS FOR YOUR SUPPORT!

 

 

Helpful Members This Week

Community Stats

30,980
Posts
117,400
Replies
38,760
Members

Latest FME

Terms & ConditionsCookie settings

Cookie policy

We use cookies to enhance and personalize your experience. If you accept you agree to our full cookie policy. Learn more about our cookies.

 
Cookie 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.