What does loading process do? It takes more than 20 hours in my case.

[hirom]

I use Spring Batch with deicision tags (and many next tags).
And loading time of the applicationContext.xml is over 20 hours.
So I want to know "what dose the loading process do?".
And I also want to know "why is the loading time so long?".


enviroment:
Spring 2.5.6
Spring Batch 2.1.2
java 1.6


sample xml is below:

<job id="jobFile" xmlns="http://www.springframework.org/schema/batch" incrementer="jobParametersIncrementer" >
     <decision decider="bean.Decider1" id="step1">
        <next on="c1" to="step2"/>
        <next on="c2" to="step3"/>
        ....
     </decision>
     
     <decision decider="bean.Decider2" id="step2">
        <next on="cc1" to="step4"/>
        <next on="cc2" to="step5"/>
        ....
     </decision>
     
     <step id="step3" next="step4">
     </step>
     
     <step id="step4" next="step5">
     </step>
     
     <step id="step5" next="....">
       <flow id="flow1" />
    </step>
</job>

<flow id="flow1">
    <step id="flow1.step1" next="flow1.step2"/>
    <step id="flow1.step2" />
</flow>

Actually there are about 20 next tags in each decision tag.
And if number of next tag is increasing , loading time will be more longer.
(also number of next tag is increasing , flow tags is increasing too. So I don't know which tag is relating to loading time.)


log sample is below:
2011/03/29 17:36:43.531 DEBUG :: Returning cached instance of singleton bean 'bean.Decider1'
2011/03/29 17:36:43.531 DEBUG :: Finished creating instance of bean '(inner bean)#12415'
2011/03/29 17:36:43.531 DEBUG :: Finished creating instance of bean '(inner bean)#12415'
2011/03/29 17:36:43.546 DEBUG :: Creating instance of bean '(inner bean)#12416'
2011/03/29 17:36:43.546 DEBUG :: Creating instance of bean '(inner bean)#12416'
2011/03/29 17:36:43.546 DEBUG :: Returning cached instance of singleton bean 'bean.Decider1'
2011/03/29 17:36:43.546 DEBUG :: Finished creating instance of bean '(inner bean)#12416'
2011/03/29 17:36:43.546 DEBUG :: Finished creating instance of bean '(inner bean)#12416'
2011/03/29 17:36:43.562 DEBUG :: Creating instance of bean '(inner bean)#12417'
2011/03/29 17:36:43.562 DEBUG :: Creating instance of bean '(inner bean)#12417'
2011/03/29 17:36:43.562 DEBUG :: Returning cached instance of singleton bean 'bean.Decider1'
2011/03/29 17:36:43.562 DEBUG :: Finished creating instance of bean '(inner bean)#12417'
2011/03/29 17:36:43.562 DEBUG :: Finished creating instance of bean '(inner bean)#12417'
2011/03/29 17:36:43.578 DEBUG :: Creating instance of bean '(inner bean)#12418'
2011/03/29 17:36:43.593 DEBUG :: Creating instance of bean '(inner bean)#12418'
2011/03/29 17:36:43.593 DEBUG :: Returning cached instance of singleton bean 'bean.Decider1'
2011/03/29 17:36:43.593 DEBUG :: Finished creating instance of bean '(inner bean)#12418'
2011/03/29 17:36:43.593 DEBUG :: Finished creating instance of bean '(inner bean)#12418'
2011/03/29 17:36:43.593 DEBUG :: Creating instance of bean '(inner bean)#12419'
2011/03/29 17:36:43.609 DEBUG :: Creating instance of bean '(inner bean)#12419'
2011/03/29 17:36:43.609 DEBUG :: Returning cached instance of singleton bean 'bean.Decider1'
2011/03/29 17:36:43.609 DEBUG :: Finished creating instance of bean '(inner bean)#12419'
2011/03/29 17:36:43.609 DEBUG :: Finished creating instance of bean '(inner bean)#12419'
2011/03/29 17:36:43.609 DEBUG :: Creating instance of bean '(inner bean)#12420'
2011/03/29 17:36:43.625 DEBUG :: Creating instance of bean '(inner bean)#12420'
2011/03/29 17:36:43.625 DEBUG :: Returning cached instance of singleton bean 'bean.Decider1'
2011/03/29 17:36:43.625 DEBUG :: Finished creating instance of bean '(inner bean)#12420'
2011/03/29 17:36:43.625 DEBUG :: Finished creating instance of bean '(inner bean)#12420'
2011/03/29 17:36:43.640 DEBUG :: Creating instance of bean '(inner bean)#12421'
2011/03/29 17:36:43.640 DEBUG :: Creating instance of bean '(inner bean)#12421'

The output is continuing more than 8000 lines.
And then log outputs "Job execution starting:".

Please help me, if you have the information about this.


Thank you very much for reading my strange english.

[Marten Deinum]

Please use [ code][/code ] tags when posting code, that way it remains readable.

For starters I suggest disabling debug logging, logging/writing to a console is slow so that has quite an impact on performance. Also if there are a lot of beans all of them need to be processed (but 20 hours! is quite long).

[arno]

perhaps some <import /> loop? looks like the same bean is created again and again. Check if some XML files don't import themselves recursively.

[hirom]

perhaps some <import /> loop? looks like the same bean is created again and again. Check if some XML files don't import themselves recursively.

Thank you for your replying.
It seems to be surely possible, I think.
I will investigate about your suggestion.
And I will report the result.

[hirom]

Now I make recursive import file, and run Spring Batch.
Then it turned out that spring throws exception, if it detects recursive import definitions.

result log is below:

Caused by: org.springframework.beans.factory.BeanDefinitionStoreException: 
Detected recursive loading of class path resource [sample/run-testManyDecider.xml] - check your import definitions!

So the cause of long time loading is not <import /> loop.
Because no exception occur at above first sample.

[Dave Syer]

Each of those "inner bean" logs is showing the creation of a DecisionState in the JobFlow. If you have >12000 such inner beans that is a *huge* flow, but even so they are only taking 10-15ms each to create, so I don't see where it adds up to 20 hours. You must have on order 5 million(!) states in your flow to take that long.

Spring Batch isn't doing anything very unusual - just creating bean definitions. Nobody has a Spring application context with 5 million beans, honestly, so you must be doing something odd.

A quick test on my PC has a DecisionState being created in more like 1-2ms so maybe your computer is feeble, or under load from something else?

I think you should explain why you need such a huge flow (probably it's the wrong tool for your job), and also look at other Spring contexts to see if they load abnormally slowly as well.

[hirom]

Please use [ code][/code ] tags when posting code, that way it remains readable.

For starters I suggest disabling debug logging, logging/writing to a console is slow so that has quite an impact on performance. Also if there are a lot of beans all of them need to be processed (but 20 hours! is quite long).

I'm sorry about code tags.
I improved above code.

Maybe it doesn't matter about debug logging.
I used Spring Batch without debug logging, and it took more than 20 hours.
So I changed to debug logging mode.

But thank you for your suggestion. I'm glad.