You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@wicket.apache.org by "Vincent (JIRA)" <ji...@apache.org> on 2010/03/24 14:48:27 UTC

[jira] Commented: (WICKET-2796) Error reporting on locked page maps, revisited

    [ https://issues.apache.org/jira/browse/WICKET-2796?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12849186#action_12849186 ] 

Vincent commented on WICKET-2796:
---------------------------------

Ok, did a proof of concept. See the attached unittest, which fails, but does print two stacktraces we can compare :)

Original stacktrace:
org.apache.wicket.WicketRuntimeException: After 1 second the Pagemap null is still locked by: Thread[Thread-2,5,main], giving up trying to get the page for path: form
	Begin of stack trace of Thread[Thread-2,5,main]
	java.lang.Thread.sleep(Native Method)
	java.lang.Thread.sleep(Thread.java:850)
	org.apache.wicket.SessionTest$1.run(SessionTest.java:16)
	java.lang.Thread.run(Thread.java:735)
	End of stack trace of Thread[Thread-2,5,main]
	at org.apache.wicket.SessionTest.test(SessionTest.java:46)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:45)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
	at java.lang.reflect.Method.invoke(Method.java:599)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
	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)


Patched stacktrace.
org.apache.wicket.WicketRuntimeException: org.apache.wicket.WicketRuntimeException: After 1 second the Pagemap null is still locked by: Thread[Thread-3,5,main], giving up trying to get the page for path: form
	at org.apache.wicket.SessionTest.test2(SessionTest.java:80)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:45)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
	at java.lang.reflect.Method.invoke(Method.java:599)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
	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)
Caused by: org.apache.wicket.WicketRuntimeException: After 1 second the Pagemap null is still locked by: Thread[Thread-3,5,main], giving up trying to get the page for path: form
	at java.lang.Thread.sleep(Native Method)
	at java.lang.Thread.sleep(Thread.java:850)
	at org.apache.wicket.SessionTest$2.run(SessionTest.java:56)
	at java.lang.Thread.run(Thread.java:735)


I like the patched stacktrace. It's more readable that the first imho. What do you think?

> Error reporting on locked page maps, revisited
> ----------------------------------------------
>
>                 Key: WICKET-2796
>                 URL: https://issues.apache.org/jira/browse/WICKET-2796
>             Project: Wicket
>          Issue Type: Improvement
>          Components: wicket
>    Affects Versions: 1.4.6
>            Reporter: Vincent
>            Priority: Minor
>         Attachments: SessionTest.java
>
>
> I'm creating this issue as suggested by Igor in the comments of the following issue: WICKET-433.
> The change done for WICKET-433 results in a quite large error message that has the potential to flood log files when running under heavy load. The error message includes a full stack of the thread that is currently locking the page map. Usually, an exception is raised that includes a message and a cause so the catcher can decide to log the complete stack or not. In this case, I'd suggest the same: create an exception, set the stack trace of the thread locking the page map on it, and throw a WicketRuntimeException with a message and a cause. Something like:
> {code}
> StackTraceElement[] stackTrace = t.getStackTrace();
> WicketRuntimeException cause = new WicketRuntimeException("Thread is locking page map.");
> cause.setStackTrace(stackTrace);
> throw new WicketRuntimeException("After " + timeout + " the Pagemap " +
>  							pageMapName + " is still locked by: " + t +
>  							", giving up trying to get the page for path: " + path,
>  							cause);
> {code}
> This issue was raised by one of the administrators on my project that was trying to break the application by doing a manual load and stress test (read: disabling javascript and submitting requests like a maniac). Since our application integrates with a web service that can take up quite some time, up to 5 seconds, a queue starts to build up because Wicket allows only one request per user to be executed because the page map is locked. While this is a great design decision in my opinion (low impact for other users), after a minute threads that are still waiting will start to abort. As quite a queue had been built up at this point and each waiting thread throws an exception with a quite verbose message (the blocking thread's stack), quite some lines will be written to the log at this time - probably on error level.
> Johan comments:
> {quote}
> how can a malicious user lock pages/pagemaps so create those kind of errors?
> These errors are more or less programming/web application errors that you need to fix
> {quote}
> Of course, you are right. This is a serious error that should never occur in a properly tuned production environment. In production, the webservice should respond much quicker and is viable for client-side caching, which we will address in future iterations.
> Our administrator's concern is that IF a user manages to build up a queue long enough to trigger this error (whatever the cause), he will face a 'log storm' that makes him effectively blind. This is the reason that stack traces on error level are not allowed in our production environment. Of course, this will only be a serious problem under very very heavy load.
> Well enough with the theoretical mumbo-jumbo, do you like the idea? Shall I cook up a proof of concept? And if successful, build a patch for this?

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.