Long server load time (not feeders?)

[.pk.]

Hi,

I've been leeching for a while so it's time to come out from shadow and say hello. Many thanks for all your knowledge sharing.

A have problem with server load time in our Tm1 enviroment. It's now ~1000secs without MaximumCubeLoadThreads and ~850secs with CubeLoadThreads>1.
Files in data folder have about 300MB, so it's quite tiny.

During startup (single cube load thread for clarity...) in tm1server.log we can observe huge gap between last "Done computing feeders..." message and "Starting PseudoElementThread. For example:

Code: Select all

12680   []   INFO   2013-03-21 11:51:16.602   TM1.Server   TM1CubeImpl::ProcessFeeders: Done computing feeders for base cube '}tp_state_validation}{c11bc047-f363-4de4-bbc5-41b2d64edbd7}'.
12680   []   INFO   2013-03-21 11:51:16.602   TM1.Server   TM1CubeImpl::ProcessFeeders: Computing feeders for base cube '}tp_state_validation}{cc795e9f-5653-4c21-8928-2c61469a063b}'.
12680   []   INFO   2013-03-21 11:51:16.602   TM1.Server   TM1CubeImpl::ProcessFeeders: Done computing feeders for base cube '}tp_state_validation}{cc795e9f-5653-4c21-8928-2c61469a063b}'.
7340   []   INFO   2013-03-21 12:04:24.976   TM1.Server   Starting PseudoElement thread.  Thread Id: 7340
12092   []   INFO   2013-03-21 12:04:24.976   TM1.Server   Starting spy thread.  Thread Id: 12092
12680   []   INFO   2013-03-21 12:04:24.976   TM1.Server   TM1 Server load time (secs) = 1042
6280   []   INFO   2013-03-21 12:04:25.584   TM1.Server   TM1 Server is ready

What is most possible reason for that?

[Paul Segal]

I'm not sure 17 odd minutes is such a long time, although I appreciate it can feel like it.

I would think it's the feeding that is taking the time. What happens if you turn Persistent Feeders on?

[.pk.]

I would think it's the feeding that is taking the time. What happens if you turn Persistent Feeders on?

Server load time dropped to 800secs. 12+ minutes gap is still in the same place. During that time one core is used on 100% (no matter what is MaximumCubeLoadThread setting).

[George Regateiro]

It is a long shot but does there happen to be a TM1S.LOG in your log directory during start up?

There is generally a gap between the cube/feeder loading and the server is ready but even on much larger models this is nowhere near 12 minutes.

Once thing that might be helpful is to turn up your logging in the properties file, maybe to debug level and see if anything additional pops up between the cubes and the ready.

[bradohare]

I agree, I would think it's probably the transaction log being a decent size and getting reloaded at startup.

[.pk.]

It is a long shot but does there happen to be a TM1S.LOG in your log directory during start up?

Yes, but it has about 1kb, I always try to save date before restart. Also there is nothing interesting in audit log.

[Gabor]

How about to remove the respective rule, to see whether it's faster then or not. Are there any consolidated elements part of feeder source or destination?
You may use }StatsByCube.cub to check the number of fed cells.

[lotsaram]

If persistent feeders is being used (AND you don't have any error messages in the log to indicate feeder files are being deleted due to time stamp violation and being re-evaluated) then removing rules will not improve start-up time. (Note are you sure that you have turned persistent feeders on? Might be useful to post the tm1s.cfg file and some of the tm1server.log file that shows feders being loaded from saved file entries to confirm)
And if you have eliminated processing unsaved transactions from the tm1s.log file also as a possibility then the next most likely culprit is a very heavy security model with lots of rule driven element security in large dimensions combined with a large number of groups. I notice you are using Contributor/Planning Applications - by chance is the dimension used for the workflow quite large? Although even then 10 minutes to apply security seems a very very long time.

[.pk.]

(Note are you sure that you have turned persistent feeders on? Might be useful to post the tm1s.cfg file and some of the tm1server.log file that shows feders being loaded from saved file entries to confirm)

Yes, I have some messages like "Loading feeders for cube *** from saved feeders file, without any errors.

And if you have eliminated processing unsaved transactions from the tm1s.log file also as a possibility then the next most likely culprit is a very heavy security model with lots of rule driven element security in large dimensions combined with a large number of groups. I notice you are using Contributor/Planning Applications - by chance is the dimension used for the workflow quite large? Although even then 10 minutes to apply security seems a very very long time.

That may be very good guess. We have 6000+ elements in }Groups Dimension, and our security model is quite complex. Most of our cubes have their own security cubes (80+ security cubes, 53 of them are loaded by rules).

I've run some tests - on our dev environment i've deleted all }ElementSecurity* and }CellSecurity* rules and cubes. Unfortunately server load time dropped only about ~40-60secs. I've tried turning on PrivilegeGenerationOptimization parameter and that gave us only ~70secs.