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
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
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!