[
https://issues.apache.org/jira/browse/WICKET-6861?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17266176#comment-17266176
]
Emond Papegaaij commented on WICKET-6861:
-----------------------------------------
I've read the same in the spec and it indeed states that my explanation is not
correct. However, I still see this behavior. I'm pretty sure that I'm clearing
the correct timer. These are some snippets from the logs:
{code}
... request that renders the form
2021-01-15 05:18:50,153 DEBUG
[nl.topicus.keyhub.web.components.panel.auth.TwoFactorAuthenticationSetupPanel]
(default task-1) Adding timer to class
nl.topicus.keyhub.web.components.panel.AccountOverviewPanel:1:account with id
account28.0
2021-01-15 05:18:50,249 DEBUG
[nl.topicus.keyhub.web.components.contextpanel.TwoFactorAuthenticationConfigPanel]
(default task-1) Adding clear timer script to cancel:
OnDomReadyHeaderItem('Wicket.Event.add('cancel2f', 'click', function()
{Wicket.Timer.clear('account28.0');})')
2021-01-15 05:18:50,252 DEBUG
[nl.topicus.keyhub.web.components.contextpanel.TwoFactorAuthenticationConfigPanel]
(default task-1) Adding clear timer script to action:
OnDomReadyHeaderItem('Wicket.Event.add('action30', 'click', function()
{Wicket.Timer.clear('account28.0');})')
... form submission request on
https://keyhub-test-app:8443/console/account?1-1.0-contextPopupPanel-form-action
2021-01-15 05:18:51,563 DEBUG
[nl.topicus.keyhub.web.components.panel.auth.TwoFactorAuthenticationSetupPanel]
(default task-1) Stopping timer account28.0
2021-01-15 05:18:51,564 DEBUG
[nl.topicus.keyhub.web.components.panel.auth.TwoFactorAuthenticationSetupPanel]
(default task-1) Removing timer
... timer request
2021-01-15 05:18:51,594 INFO
[nl.topicus.cobra.app.LoggingRequestCycleListener] (default task-7) Start of
request:
sessionId=6OY6wBc7OShw8yJ8whfnmVJpU-F2jTN-e8fsfy2t,isTemporary=false,httpUrl=[https://keyhub-test-app:8443/console/account?1-1.0-account&_=1610687929268],requestedSessionId=6OY6wBc7OShw8yJ8whfnmVJpU-F2jTN-e8fsfy2t
2021-01-15 05:18:51,604 WARN [RequestCycleExtra] (default task-7)
********************************
2021-01-15 05:18:51,604 WARN [RequestCycleExtra] (default task-7) Handling the
following exception: org.apache.wicket.behavior.InvalidBehaviorIdException:
Cannot find behavior with id '0' on component
'nl.topicus.keyhub.web.components.panel.AccountOverviewPanel:account' in page
'[Page class = nl.topicus.keyhub.web.pages.AccountProfielPage, id = 1, render
count = 1]'. Perhaps the behavior did not properly implement getStatelessHint()
and returned 'true' to indicate that it is stateless instead of returning
'false' to indicate that it is stateful.
{code}
As you can see in the logs, the ids and component paths all match.
Unfortunately, I cannot easily confirm that my proposed change fixes the
problem. I'll try if I can patch the js locally, but as the error only occurs
once every 1 or 2 weeks, it will take some time to verify (at least a month,
probably longer). For now, let's leave the code in Wicket as is, until we've
verified that it actually fixes the issue.
> Possible race condition in clearing and triggering of Wicket timers
> -------------------------------------------------------------------
>
> Key: WICKET-6861
> URL: https://issues.apache.org/jira/browse/WICKET-6861
> Project: Wicket
> Issue Type: Bug
> Components: wicket-core
> Affects Versions: 9.2.0
> Reporter: Emond Papegaaij
> Priority: Minor
>
> In our test suite we see some intermittent failures related to
> {{AbstractAjaxTimerBehavior}}. At a few places in our application, we use a
> background poller at a 1 sec interval that checks for an out-of-band
> submission of the form data. So the user either has to fill the form via the
> web interface or via some other route. Either route can complete the form,
> but as soon as one of the two is triggered, the other must stop. The race
> condition lies in the {{AbstractAjaxTimerBehavior}} triggering while the user
> has already submitted the form manually.
> The naive implementation would stop {{AbstractAjaxTimerBehavior}} via
> {{Wicket.Timer.clear('timer0')}} in the Ajax response of the form submit.
> However, this results in a very large gap between the moment of submission
> and the actual moment the timer is stopped. To fix this, we've added the
> following code to the {{AjaxSubmitLink}}:
> {code:java}
> @Override
> public void renderHead(IHeaderResponse response) {
> super.renderHead(response);
> response.render(OnDomReadyHeaderItem.forScript(
> "Wicket.Event.add('" + getMarkupId() + "', 'click', " +
> "function() {Wicket.Timer.clear('" + getTimerId() + "');})"));
> }
> {code}
> This puts the call to {{Wicket.Timer.clear}} before the actual Ajax submit
> and should therefore prevent the timer from triggering after the Ajax submit
> is done. However, in very rare occurrences we still see the timer triggering.
> When it happens, the timer is always directly after the Ajax submit (often
> within 10ms). This makes us believe the current implementation has a race
> condition in the following way:
> * The user clicks the Ajax submit link
> * The execution of the event handlers is started in the browser
> * At this moment the {{setTimeout}} triggers, but it is suspended because JS
> is single threaded and the browser is already execution JS in response to UI
> interaction
> * The first event handler now clears the timer
> * The second event handler performs the Ajax call
> * Now the JS executor is freed and the timer function is executed
> Although I'm not entirely at home in the execution model of JS in a browser,
> this is the only explanation I could come up with. There is no way to
> reproduce it, other than run a complex test suite 1000ths of times. My
> proposed fix is to replace the timeout function in {{wicket-ajax-jquery.js}}
> in {{Wicket.Timer.set}} with this:
> {code:javascript}
> Wicket.TimerHandles[timerId] = setTimeout(function() {
> if (timerId in Wicket.TimerHandles) {
> Wicket.Timer.clear(timerId);
> f();
> }
> }, delay);
> {code}
> This should prevent the function {{f()}} to be executed after the timer has
> been cleared (Wicket.Timer.clear deletes the {{timerId}} from
> {{Wicket.TimerHandles}}.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
