0

ZK 5 auto-wiring, after-compose running slow and slower, bug/memory leakage?

asked 2010-04-26 08:14:45 +0800

juwian gravatar image juwian
96 1 3

ZK 5.01 (in a spring 3 environment) seems very slow, as well as have some major issues (result of some kind of memory leakage?) when utilizing controllers that extend Window and implement AfterCompose in order to make use of auto-wiring of variables and events for components in a underlying zul-page in which annotated data-bindings are used extensively.

In an abstract controller that implements AfterCompose (and extends Window) I've got:

@Override
public void afterCompose() {
  Components.wireVariables(this, this);
  Components.addForwards(this, this);
}


For every request for any ZUL-page (that is using a controller extending the abstract controller mentioned above) this very method "afterCompose" takes more and more time to execute. The question is why.

I've done some TPTP profiling and the application service layer is not a bottle-neck, but rather "afterCompose()" as well as bsh (beanshell - seems to consume huge amounts of time for parsing and interpreting) and EHCache (DiskStore.throwableSafeFlushSpoolIfRequired())

I monitored afterCompose for a series of requests for a ZUL page and the execution-time for "afterCompose" seems to double for every request for the ZUL-page!

Something is seriously wrong here.. Memory leakage? Thread syncronizations? Is beanshell involved, something there which is messed up? And why is the auto-wiring in ZK 5 so slow even initially?

The ZUL-pages are all pretty simple, some with only one listbox and some buttons, others with 10-20 fields, it's not reasonable that wiring any of these pages should cost 3-4 seconds at best, and 15-50 seconds at worst! (i.e., it takes longer and longer time to load any ZUL page for every request made, and it is not the application service that is getting slower..but ZK..beanshell..afterCompose)

Any ideas?

delete flag offensive retag edit

40 Replies

Sort by ยป oldest newest

answered 2010-04-28 04:44:09 +0800

juwian gravatar image juwian
96 1 3

It seems as if ZK through Spring(?) upon loading a ZUL-page (referencing a controller using SptingDelegateVariableResolver through the attribute "use" or "apply" in a window component) attempts to wire every field in the controller (fields like _width, _visibility, _height, _zkBindingComposer etc - depends on what type of controller one is using and what ZK-superclass it extends)

ZK/Spring seems to call (SpringDelegatingVariableResolver?) getBean(name) for every protected/private field (which is strange) it finds in the controller (using reflections?) eventhough none of these are annotated as @Resource or @Autowired

It is also evident that more and more fields are attempted to be wired by ZK-Spring and since none of them should be (since they are just regular fields and not annotated for DI by spring) it results in every increasing load-time for any ZUL-page referencing a Spring-managed controller (controler-annotated bean with scope prototype). This is a major issue.

Hmm..really strange..is this a bug in the Spring-ZK integration? Anyone?

link publish delete flag offensive edit

answered 2010-04-28 05:13:02 +0800

terrytornado gravatar image terrytornado flag of Germany
9393 3 7 16
http://www.oxitec.de/

updated 2010-04-28 05:17:21 +0800

@raevel2
@juwian

Interesting. Please can someone of you post the needed lines for enabling the Tracing in the log4j.xml

I remember me that as we update our sample app 3.6.3 to spring3 and go away from the window and afterCompose stuff to GenericForwardComposer that the speed is gone much better.
So, i will have a look early for our new zk5 app.

thanks
Stephan

link publish delete flag offensive edit

answered 2010-04-28 05:48:13 +0800

ashishd gravatar image ashishd flag of Taiwan
1972 6

Hi All,
I have added an issue to zkspring project for this and currently investigating it. Thanks for all your feedback and sample code. I'll get back to you asap.

Thanks
- Ashish

link publish delete flag offensive edit

answered 2010-04-28 06:36:11 +0800

linthar gravatar image linthar
36

terrytornado:
log4j trace lines (in the example, pace the lines in the file leak/WebContent/WEB-INF/classes/log4j.properties)

log4j.rootLogger=TRACE, CONSOLE
log4j.appender.CONSOLE=org.apache.log4j.ConsoleAppender
log4j.appender.CONSOLE.Threshold=TRACE
log4j.appender.CONSOLE.layout=org.apache.log4j.PatternLayout
log4j.appender.CONSOLE.layout.ConversionPattern=- %d [%t] %-5p - %m%n

link publish delete flag offensive edit

answered 2010-04-28 06:44:43 +0800

juwian gravatar image juwian
96 1 3

In order to get log4j working you need to add the following to web.xml under /leak/WEB-INF :

<context-param>
  <param-name>log4jConfigLocation</param-name>
  <param-value>/WEB-INF/log4j.properties</param-value>
</context-param>

<context-param>
  <param-name>log4jRefreshInterval</param-name>
  <param-value>1000</param-value>
</context-param>

<listener>
  <listener-class>org.springframework.web.util.Log4jConfigListener</listener-class>
</listener>


Then add a log4j.properties under leak/WEB-INF/ with the contents as posted by linthar above.

link publish delete flag offensive edit

answered 2010-04-28 07:10:28 +0800

linthar gravatar image linthar
36

my 2 cents:
Is far as I know, the origin of those autowiring failures, starts at this method

org.zkoss.zk.ui.Components.Wire.wireOthers()

Is like a default autowiring "byName" (even if you configure Spring autowire as "byType").

1 - Even that, It seems that "old" composers still alive and trying to be autoproxied (reference/garbage collector ? )
2 - When is executed ZkConfigDefinitionParser? (I could avoid "No bean named 'zkBindingComposer' adding a Spring bean in my app" )

<bean name="zkBindingComposer" class="org.zkoss.spring.config.ZkSpringBeanBindingComposer" />

link publish delete flag offensive edit

answered 2010-04-28 14:19:07 +0800

juwian gravatar image juwian
96 1 3

To me it seems to break down to 2 issues.

1) Old composers still being alive and some kind of DI being performed by ZK/Spring on them.
2) The strange issue that ZK/Spring attempts DI (and fails since no such spring-managed-beans exist) for every field it finds in controller-classes (even though they're not annotated with @Autowire @Resource, most of them even being private to ZK super-classes such as GenericForwardComposer!)

These issues result in ever increasing load-time for any ZUL-page.


Spring-managed controllers not referenced and loaded through a ZK-component referencing them through "use" or "apply" does not seem introduce any of these issues..

link publish delete flag offensive edit

answered 2010-05-10 04:25:21 +0800

ryanwong00 gravatar image ryanwong00
63 1

I just experience this issue as well.
The worst part of this issue is that the "No bean named .." errors are cumulative amongst all sessions. For example, when user A load it's page at PC A, the server may prompt, let say, 10 such messages. When user B then load it's page at PC B, the server will prompt 10+10 -> 20 such messages.
Assuming that a composer is loaded N times, the server will suffer 10*N error at each loading. Basically, the number of errors will grow exponentially and the server will corrupt within short period of times.

Hopes that the issue will be solved soon, or, is there any workaround to avoid it?

link publish delete flag offensive edit

answered 2010-05-10 13:05:53 +0800

juwian gravatar image juwian
96 1 3

updated 2010-05-10 13:06:26 +0800

Hi! Is there anyone in the ZK community working on this issue?

A ticket was opened the 28th of April by "ashishd" but I haven't seen any activity on that one since then..

The issue seems to be the most serious bug right now in ZK-Spring project affecting many otherwise happy users so I hope someone is working with it..

link publish delete flag offensive edit

answered 2010-05-10 14:26:51 +0800

terrytornado gravatar image terrytornado flag of Germany
9393 3 7 16
http://www.oxitec.de/

updated 2010-05-10 14:27:19 +0800

Hi juwian,

we use only 3 or 4 pieces from them, because spring should manage our zk app and not zk should manage spring.
So i will have a look on it because it's interesting for us too.
Attached my log4j.xml. Please can you copy the coresponding entries to it for showing 'out of the box' the trace.

thx
Stephan

log4j.xm
l

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/"
	debug="false">

	<appender name="STDOUT" class="org.apache.log4j.ConsoleAppender">
		<param name="Target" value="System.out" />
		<param name="Threshold" value="ALL" />
		<layout class="org.apache.log4j.PatternLayout">
			<param name="ConversionPattern" value="%d{ISO8601} %-6p [%t] %c{1} M[%M] - %m\n" />
		</layout>
		<filter class="org.apache.log4j.varia.LevelRangeFilter">
			<param name="LevelMax" value="WARN" />
		</filter>
	</appender>

	<appender name="STDERR" class="org.apache.log4j.ConsoleAppender">
		<param name="Target" value="System.err" />
		<param name="Threshold" value="ERROR" />
		<layout class="org.apache.log4j.PatternLayout">
			<param name="ConversionPattern" value="%d{ISO8601} %-6p [%t] %c{1} M[%M] - %m\n" />
		</layout>
	</appender>

	<appender name="FILE" class="org.apache.log4j.RollingFileAppender">
		<param name="File" value="./out.log.txt" />
		<param name="MaxFileSize" value="5MB" />
		<param name="MaxBackupIndex" value="2" />
		<param name="Threshold" value="ALL" />
		<layout class="org.apache.log4j.PatternLayout">
			<param name="ConversionPattern" value="%d{ISO8601} %-6p [%t] %c{1} M[%M] - %m\n" />
		</layout>
	</appender>

	<category name="org.apache">
		<priority value="INFO" />
	</category>
	<category name="org.hibernate">
		<priority value="WARN" />
	</category>
	<category name="net.sf.ehcache">
		<priority value="ERROR" />
	</category>

	<category name="org.xml">
		<priority value="INFO" />
	</category>
	<category name="org.apache">
		<priority value="INFO" />
	</category>
	<category name="httpclient.wire">
		<priority value="INFO" />
	</category>
	<category name="org.hibernate.proxy">
		<priority value="FATAL" />
	</category>

	<category name="org.springframework.beans.factory">
		<priority value="INFO" />
	</category>
	<category name="org.springframework">
		<priority value="INFO" />
	</category>


	<root>
		<level value="ALL" />
		<appender-ref ref="STDOUT" />
		<appender-ref ref="STDERR" />
		<!-- appender-ref ref="FILE" /-->
	</root>

</log4j:configuration>

link publish delete flag offensive edit
Your reply
Please start posting your answer anonymously - your answer will be saved within the current session and published after you log in or create a new account. Please try to give a substantial answer, for discussions, please use comments and please do remember to vote (after you log in)!

[hide preview]

Question tools

Follow

RSS

Stats

Asked: 2010-04-26 08:14:45 +0800

Seen: 3,347 times

Last updated: Sep 02 '11

Support Options
  • Email Support
  • Training
  • Consulting
  • Outsourcing
Learn More