Performance issue

[Andrey]

Hello!

Powermock looks great, but when I tried to use it I ran into a
performance problem.
I am trying to mock widgets from the GXT library (extjs.com) - an
extension for GWT widgets.

Such code:

import com.extjs.gxt.ui.client.widget.button.Button;
...
Button button = createMock(Button.class);

runs for about a minute which is unacceptable for a unit test.

Any other mocking including mocking of the GWT widgets is fast. But
GXT widgets mocking is very slow.

What can take so much time? Maybe I miss something. As I see only
first mock takes much time. All the consequent mocks are fast. Looks
like Powermock generates some code or something.

Hope you could help me.
Thanks in advance!

[Johan Haleby]

Hi,

I've never experienced that before, taking a minute or more to load is unacceptable of course. I cannot say why it's taking so long though. Something that comes to mind is if Button has a static initializer or depend on another class that has a static initializer that tries to load some resources for 60s but then timeouts. But this is pure speculation of course. Could you run the code in a profiler and see where exactly the time is spent?

/Johan

[Andrey]

Hello!

There is the code:

import static org.powermock.api.easymock.PowerMock.*;

import org.junit.BeforeClass;
import org.junit.Test;
import org.junit.runner.RunWith;
import
org.powermock.core.classloader.annotations.SuppressStaticInitializationFor;
import org.powermock.modules.junit4.PowerMockRunner;

import com.extjs.gxt.ui.client.widget.button.Button;
import com.google.gwt.junit.GWTMockUtilities;

@RunWith(PowerMockRunner.class)
public class LoadTest {
private static void time(int step) {
System.out.println(step + ": " + System.currentTimeMillis());
System.out.flush();
}

@BeforeClass
public static void setup() {
time(1);
}

@Test
@SuppressStaticInitializationFor
("com.extjs.gxt.ui.client.widget.Component")
public void test1() {
time(2);

GWTMockUtilities.disarm();

time(3);

createMock(Button.class);

time(4);
}
}

There is the output:
1: 1257244963170
2: 1257244963191
3: 1257244963201
4: 1257244987480

As you can see interval 3-4 takes about 30 sec.

When trying to profile with Eclipse TPTP I receive the following
exception:
java.lang.ClassFormatError: Invalid length 64106 in LocalVariableTable
in class file com/extjs/gxt/ui/client/widget/Component
at java.lang.ClassLoader.defineClass1(Native Method)
at java.lang.ClassLoader.defineClass(ClassLoader.java:621)
at java.lang.ClassLoader.defineClass(ClassLoader.java:466)
at org.powermock.core.classloader.MockClassLoader.loadMockClass
(MockClassLoader.java:211)
at org.powermock.core.classloader.MockClassLoader.loadModifiedClass
(MockClassLoader.java:146)
at org.powermock.core.classloader.DeferSupportingClassLoader.loadClass
(DeferSupportingClassLoader.java:61)
at java.lang.ClassLoader.loadClass(ClassLoader.java:252)
at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:320)
at java.lang.ClassLoader.defineClass1(Native Method)
at java.lang.ClassLoader.defineClass(ClassLoader.java:621)
at java.lang.ClassLoader.defineClass(ClassLoader.java:466)
at org.powermock.core.classloader.MockClassLoader.loadUnmockedClass
(MockClassLoader.java:190)
at org.powermock.core.classloader.MockClassLoader.loadModifiedClass
(MockClassLoader.java:148)
at org.powermock.core.classloader.DeferSupportingClassLoader.loadClass
(DeferSupportingClassLoader.java:61)
at java.lang.ClassLoader.loadClass(ClassLoader.java:252)
at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:320)
at java.lang.ClassLoader.defineClass1(Native Method)
at java.lang.ClassLoader.defineClass(ClassLoader.java:621)
at java.lang.ClassLoader.defineClass(ClassLoader.java:466)
at org.powermock.core.classloader.MockClassLoader.loadUnmockedClass
(MockClassLoader.java:190)
at org.powermock.core.classloader.MockClassLoader.loadModifiedClass
(MockClassLoader.java:148)
at org.powermock.core.classloader.DeferSupportingClassLoader.loadClass
(DeferSupportingClassLoader.java:61)
at java.lang.ClassLoader.loadClass(ClassLoader.java:252)
at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:320)
at ru.aml.app.client.file.LoadTest.test1(LoadTest.java:35)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke
(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke
(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.junit.internal.runners.TestMethod.invoke(TestMethod.java:66)
at
org.powermock.modules.junit4.internal.impl.PowerMockJUnit44RunnerDelegateImpl
$PowerMockJUnit44MethodRunner.runTestMethod
(PowerMockJUnit44RunnerDelegateImpl.java:322)
at org.junit.internal.runners.MethodRoadie$2.run(MethodRoadie.java:
86)
at
org.junit.internal.runners.MethodRoadie.runBeforesThenTestThenAfters
(MethodRoadie.java:94)
at
org.powermock.modules.junit4.internal.impl.PowerMockJUnit44RunnerDelegateImpl
$PowerMockJUnit44MethodRunner.executeTest
(PowerMockJUnit44RunnerDelegateImpl.java:309)
at
org.powermock.modules.junit4.internal.impl.PowerMockJUnit44RunnerDelegateImpl
$PowerMockJUnit44MethodRunner.runBeforesThenTestThenAfters
(PowerMockJUnit44RunnerDelegateImpl.java:297)
at org.junit.internal.runners.MethodRoadie.runTest(MethodRoadie.java:
84)
at org.junit.internal.runners.MethodRoadie.run(MethodRoadie.java:49)
at
org.powermock.modules.junit4.internal.impl.PowerMockJUnit44RunnerDelegateImpl.invokeTestMethod
(PowerMockJUnit44RunnerDelegateImpl.java:222)
at
org.powermock.modules.junit4.internal.impl.PowerMockJUnit44RunnerDelegateImpl.runMethods
(PowerMockJUnit44RunnerDelegateImpl.java:161)
at
org.powermock.modules.junit4.internal.impl.PowerMockJUnit44RunnerDelegateImpl
$1.run(PowerMockJUnit44RunnerDelegateImpl.java:135)
at org.junit.internal.runners.ClassRoadie.runUnprotected
(ClassRoadie.java:34)
at org.junit.internal.runners.ClassRoadie.runProtected
(ClassRoadie.java:44)
at
org.powermock.modules.junit4.internal.impl.PowerMockJUnit44RunnerDelegateImpl.run
(PowerMockJUnit44RunnerDelegateImpl.java:133)
at
org.powermock.modules.junit4.common.internal.impl.JUnit4TestSuiteChunkerImpl.run
(JUnit4TestSuiteChunkerImpl.java:112)
at
org.powermock.modules.junit4.common.internal.impl.AbstractCommonPowerMockRunner.run
(AbstractCommonPowerMockRunner.java:44)
at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run
(JUnit4TestReference.java:46)
at org.eclipse.jdt.internal.junit.runner.TestExecution.run
(TestExecution.java:38)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests
(RemoteTestRunner.java:467)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests
(RemoteTestRunner.java:683)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run
(RemoteTestRunner.java:390)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main
(RemoteTestRunner.java:197)

Andrey

On 3 ноя, 10:09, Johan Haleby <johan.hal...@gmail.com> wrote:
> Hi,
>
> I've never experienced that before, taking a minute or more to load is
> unacceptable of course. I cannot say why it's taking so long though.
> Something that comes to mind is if Button has a static initializer or depend
> on another class that has a static initializer that tries to load some
> resources for 60s but then timeouts. But this is pure speculation of course.
> Could you run the code in a profiler and see where exactly the time is
> spent?
>
> /Johan
>

[Johan Haleby]

Does it make any difference if you move "@SuppressStaticInitializationFor("com.extjs.gxt.ui.client.widget.Component")" to the class-level instead? I.e. right under @RunWith?

[Andrey]

No difference.

@RunWith(PowerMockRunner.class)
@SuppressStaticInitializationFor
("com.extjs.gxt.ui.client.widget.Component")
public class LoadTest {
...

The output is:

1: 1257249238679
2: 1257249238697
3: 1257249238711
4: 1257249262877

And the TPTP profiler throws exactly the same exception:

java.lang.ClassFormatError: Invalid length 64106 in
LocalVariableTable

I should say that SuppressStaticInitializationFor must present in the
test because Component class tries to execute some native methods
statically. That's the main reason why I want to use PowerMock. It
could really help me there.

On 3 ноя, 14:46, Johan Haleby <johan.hal...@gmail.com> wrote:
> Does it make any difference if you move
> "@SuppressStaticInitializationFor("com.extjs.gxt.ui.client.widget.Component")"
> to the class-level instead? I.e. right under @RunWith?
>

[Andrey]

I must add that I also tried not to suppress static initializer but to
suppress native method calls themselves using @PrepareOnlyThisForTest
and suppress(method(...)) but it also takes a lot of time - about a
half or a whole minute.

[Johan Haleby]

I would really like to know what's happening when you call createMock(Button.class) in order to figure out exactly where the time is spent.. Is it possible for you to create a small project that demonstrates this issue and upload it to our google group so that I can have a look at it? Otherwise it will be hard to find out I think. Perhaps you could step into the PowerMock code and try to locate which method that causes this?

/Johan

[Andrey]

The problem is that the version of GXT I am using is commercial and I
cannot distribute it.
I tried to debug and I see that there is some kind of very long
cycling around:

Thread [main] (Suspended (breakpoint at line 195 in URLClassLoader
$1))
URLClassLoader$1.run() line: 195 [local variables unavailable]
AccessController.doPrivileged(PrivilegedExceptionAction<T>,
AccessControlContext) line: not available [native method]
Launcher$AppClassLoader(URLClassLoader).findClass(String) line: 188
Launcher$AppClassLoader(ClassLoader).loadClass(String, boolean) line:
307
Launcher$AppClassLoader.loadClass(String, boolean) line: 301
Launcher$AppClassLoader(ClassLoader).loadClass(String) line: 252
Launcher$AppClassLoader(ClassLoader).loadClassInternal(String) line:
320
MockClassLoader.<init>(String[], String[]) line: 65
AbstractTestSuiteChunkerImpl$1.run() line: 214
AbstractTestSuiteChunkerImpl$1.run() line: 212
AccessController.doPrivileged(PrivilegedAction<T>) line: not
available [native method]
JUnit4TestSuiteChunkerImpl
(AbstractTestSuiteChunkerImpl<T>).createNewClassloader(Class<?>, String
[], String[]) line: 212
JUnit4TestSuiteChunkerImpl(AbstractTestSuiteChunkerImpl<T>).chunkClass
(Class<?>) line: 184
JUnit4TestSuiteChunkerImpl(AbstractTestSuiteChunkerImpl<T>).<init>
(Class<?>...) line: 106
JUnit4TestSuiteChunkerImpl(AbstractTestSuiteChunkerImpl<T>).<init>
(Class<?>) line: 99
JUnit4TestSuiteChunkerImpl.<init>(Class<?>,
Class<PowerMockJUnitRunnerDelegate>) line: 57
PowerMockRunner(AbstractCommonPowerMockRunner).<init>(Class<?>,
Class<PowerMockJUnitRunnerDelegate>) line: 34
PowerMockRunner.<init>(Class<?>) line: 27
NativeConstructorAccessorImpl.newInstance0(Constructor, Object[])
line: not available [native method]
NativeConstructorAccessorImpl.newInstance(Object[]) line: 39
DelegatingConstructorAccessorImpl.newInstance(Object[]) line: 27
Constructor<T>.newInstance(Object...) line: 513
AnnotatedBuilder.buildRunner(Class<Runner>, Class<?>) line: 31
AnnotatedBuilder.runnerForClass(Class<?>) line: 24
AnnotatedBuilder(RunnerBuilder).safeRunnerForClass(Class<?>) line:
57
AllDefaultPossibilitiesBuilder.runnerForClass(Class<?>) line: 29
AllDefaultPossibilitiesBuilder(RunnerBuilder).safeRunnerForClass
(Class<?>) line: 57
ClassRequest.getRunner() line: 24
JUnit4TestClassReference(JUnit4TestReference).<init>(Request) line:
29
JUnit4TestClassReference.<init>(Class<?>) line: 25
JUnit4TestLoader.createTest(Class<?>, String) line: 40
JUnit4TestLoader.loadTests(Class[], String, String[],
RemoteTestRunner) line: 30
RemoteTestRunner.runTests(String[], String, TestExecution) line: 452
RemoteTestRunner.runTests(TestExecution) line: 683
RemoteTestRunner.run() line: 390
RemoteTestRunner.main(String[]) line: 197

This trace repeats lot of times. Is it loading lots of classes there?

On 3 ноя, 15:32, Johan Haleby <johan.hal...@gmail.com> wrote:
> I would really like to know what's happening when you call
> createMock(Button.class) in order to figure out exactly where the time is
> spent.. Is it possible for you to create a small project that demonstrates
> this issue and upload it to our google group so that I can have a look at
> it? Otherwise it will be hard to find out I think. Perhaps you could step
> into the PowerMock code and try to locate which method that causes this?
>
> /Johan
>

> ...
>
> продолжение »

[Johan Haleby]

Hi,

Hmm, are you saying that "JUnit4TestSuiteChunkerImpl (AbstractTestSuiteChunkerImpl<T>).createNewClassloader(Class<?>, String[], String[]) line: 212" is called many times or just loadClass/findClass in the classloader? If it's the first alternative then something may be very wrong.

Just to make it clear, you only have one test-method in your test and you've placed all PowerMock annotations at the class-level of the test?

/Johan

[Andrey]

No that's only loadClass/findClass, not createNewClassLoader.
I am sorry that I can't provide a working example. There's a free
version of GXT but it is obsolete.

At the moment my test is:

@RunWith(PowerMockRunner.class)
@SuppressStaticInitializationFor
("com.extjs.gxt.ui.client.widget.Component")
public class LoadTest {

@Test
public void test() {
GWTMockUtilities.disarm();

createMock(Button.class);
}
}

There is no more methods.

On 3 ноя, 18:46, Johan Haleby <johan.hal...@gmail.com> wrote:
> Hi,
>
> Hmm, are you saying that "JUnit4TestSuiteChunkerImpl
> (AbstractTestSuiteChunkerImpl<T>).createNewClassloader(Class<?>, String[],
> String[]) line: 212" is called many times or just loadClass/findClass in the
> classloader? If it's the first alternative then something may be very wrong.
>
> Just to make it clear, you only have one test-method in your test and you've
> placed all PowerMock annotations at the class-level of the test?
>
> /Johan
>

> ...
>
> продолжение >>

[Johan Haleby]

Hi,

It's very hard for me to figure out what's wrong. It would be extremely helpful if you could try out if you experience the same issues with the free version and in that case provide me with a running example (preferably a maven project) that demonstrates the issue. Would this be possible?

/Johan

2009/11/3 Andrey <min...@gmail.com>