Opened on 08/25/2017 at 08:06:03 AM

Closed on 10/23/2018 at 10:01:34 AM

#5572 closed defect (fixed)

FilterEngine does not update subscription(s)

Reported by: asmirnov Assignee: sergz
Priority: P2 Milestone:
Module: Libadblockplus-Android Keywords:
Cc: sergz Blocked By:
Blocking: Platform: Android
Ready: yes Confidential: no
Tester: Unknown Verified working: no
Review URL(s):

https://codereview.adblockplus.org/29558607/
https://codereview.adblockplus.org/29567613/

Description

Environment

In order to provider better UX (do adblocking on the very first app launch when subscription files are not yet downloaded) we can use preloaded subscription. We have android web request wrapper for it: https://github.com/adblockplus/libadblockplus-android/blob/master/libadblockplus-android/src/org/adblockplus/libadblockplus/android/AndroidWebRequestResourceWrapper.java.
In the app we have to init preloaded subscription files (and put them in app resources) like following:
https://github.com/adblockplus/libadblockplus-android/blob/master/libadblockplus-android-webviewapp/src/org/adblockplus/libadblockplus/android/webviewapp/Application.java#L48

On the very first app launch wrapper will intercept download attempt, return subscription body from app resources (instead of actual downloading), request subscription update immediately and remember intercepted URL (in order to intercept it once only).

However i was able to see a bug 2 times:
1) only 1 subscription was requested to be downloaded
2) both subscriptions were not requested to be downloaded.

The log files are attached.
libadblockplus-binaries used are hg:8748632996d3

How to reproduce

  1. Clear app cache (to remove subscription files) or reinstall the app
  2. Launch the app
  3. Make sure subscriptions download requests are intercepted
  4. Make sure 1 or both forced subscription updates are not invoked by filter engine.

...

Observed behaviour

There is no download request for 1 or both subscription files

Expected behaviour

Both subscription files are downloaded after intercepted (and forced to be downloaded).

Attachments (2)

1.txt (8.4 KB) - added by asmirnov on 08/25/2017 at 08:07:14 AM.
1 subscription is not force updated
2.txt (5.2 KB) - added by asmirnov on 08/25/2017 at 08:08:24 AM.
both subscription files are not force downloaded

Download all attachments as: .zip

Change History (21)

Changed on 08/25/2017 at 08:07:14 AM by asmirnov

1 subscription is not force updated

Changed on 08/25/2017 at 08:08:24 AM by asmirnov

both subscription files are not force downloaded

comment:1 Changed on 08/25/2017 at 08:10:07 AM by asmirnov

see updateFiltersAsync() invocation and then Downloading from: for it (missing)

comment:2 Changed on 08/25/2017 at 08:10:19 AM by asmirnov

  • Ready set

comment:3 Changed on 08/25/2017 at 08:11:14 AM by asmirnov

  • Summary changed from FilterEngine does not updates subscription(s) to FilterEngine does not update subscription(s)

comment:4 Changed on 08/25/2017 at 08:15:55 AM by sergz

  • Cc sergz added
  • Summary changed from FilterEngine does not update subscription(s) to FilterEngine does not updates subscription(s)

comment:5 Changed on 08/25/2017 at 08:16:51 AM by sergz

  • Summary changed from FilterEngine does not updates subscription(s) to FilterEngine does not update subscription(s)

comment:6 Changed on 09/01/2017 at 07:59:24 AM by sergz

  • Owner set to sergz
  • Priority changed from P3 to P2

comment:7 Changed on 09/14/2017 at 12:33:06 PM by sergz

  • Owner sergz deleted

comment:8 Changed on 09/28/2017 at 11:29:28 AM by sergz

  • Component changed from Libadblockplus to Libadblockplus-Android
  • Owner set to sergz
  • Review URL(s) modified (diff)

comment:9 Changed on 09/28/2017 at 12:13:36 PM by abpbot

A commit referencing this issue has landed:
Issue 5572 - fix stringBeginsWith in Util.cpp

comment:10 Changed on 10/06/2017 at 08:53:41 AM by sergz

It seems that in addition there is the following race condition:
Simply put, when the downloading of a subscription in order to update filters is scheduled, this downloading does nothing because the URL is still being downloaded because the original response is not sent to JS part yet.

In details:
Java AndroidWebRequestResourceWrapper, implementing WebRequest and running in a worker thread, calls a listener which
calls Java ...filterEngine.updateFiltersAsync which
finally schedules within a worker thread a call of C++ subscription.UpdateFilters() which
calls JS Synchronizer.execute(subscription) which
finally schedules within a timer thread a call of JS Downloader._download(downloadable, redirects) with zero delay which
at the beginning checks whether downloadable.url is in this._downloading and immediately returns if it's true but it is true because
the URL is removed from this._downloading later. "Later" is when Java AndroidWebRequestResourceWrapper returns the value, and corresponding C++ implementation calls the JS callback which finally calls a "load" listener of XMLHttpRequest in downloader.js.

How to solve it

Strictly speaking, it should be properly implemented in the JS core (#5069), where it seems rather difficult to implement it with such race condition.

As a quick hacky fix reducing the probability of this race condition I can propose to create a delay right before the call of C++ subscription.UpdateFilters(). However, instead of putting a sleep I would rather recommend to schedule the currently scheduled function not in a thread but in a timer with the delay.
[I have tested this approach for a while locally and going to file a code review with it].

Another not an elegant but a correct option to fix it without touching the core would be to subscribe to a subscription change (e.g. "subscription.lastDownload") because it's fired after removing of the subscription URL from _downloading and to schedule the updating at that point. However, it also requires to be careful with any race conditions and of course one should remove this callback afterwards.

comment:11 Changed on 10/06/2017 at 09:08:27 AM by sergz

  • Review URL(s) modified (diff)

Add the review with the "quick hacky" approach.

comment:12 follow-up: Changed on 10/06/2017 at 10:29:54 AM by asmirnov

We can probably solve it by moving invocation of engine.filterEngine.updateFiltersAsync(url); into main thread after AndroidWebRequestResourceWrapper exits (change the order). This means AndroidWebRequestResourceWrapper will return value and URL is removed from URLs to update and after that updateFiltersAsync(url) will be invoked. In Android it will be posting Runnable to the Handler instance like handler.post(). The handler should be created in main thread.

Last edited on 10/06/2017 at 10:37:48 AM by asmirnov

comment:13 in reply to: ↑ 12 ; follow-up: Changed on 10/06/2017 at 10:40:55 AM by sergz

Replying to asmirnov:

We can probably solve it by moving invocation of engine.filterEngine.updateFiltersAsync(url); into main thread after AndroidWebRequestResourceWrapper exits (change the order). This means AndroidWebRequestResourceWrapper will return value and URL is removed from URLs to update and after that updateFiltersAsync(url) will be invoked.

It's not really clear how one can ensure in the main thread that the URL is removed from _downloading?
In addition if the call of a callback of asynchronous WebRequest ensured that the URL is not considered anymore as being downloeded, then one could (actually should) implement asynchronous IWebRequest and schedule the update after calling of the callback. However, there is still a way to break it by changing the core, so I would rather consider for present the minimal and the easiest way to have it working in most cases and actually fix it in the core.

comment:14 in reply to: ↑ 13 ; follow-up: Changed on 10/06/2017 at 10:51:30 AM by asmirnov

Replying to sergz:

Replying to asmirnov:

We can probably solve it by moving invocation of engine.filterEngine.updateFiltersAsync(url); into main thread after AndroidWebRequestResourceWrapper exits (change the order). This means AndroidWebRequestResourceWrapper will return value and URL is removed from URLs to update and after that updateFiltersAsync(url) will be invoked.

It's not really clear how one can ensure in the main thread that the URL is removed from _downloading?
In addition if the call of a callback of asynchronous WebRequest ensured that the URL is not considered anymore as being downloeded, then one could (actually should) implement asynchronous IWebRequest and schedule the update after calling of the callback. However, there is still a way to break it by changing the core, so I would rather consider for present the minimal and the easiest way to have it working in most cases and actually fix it in the core.

If i understand the problem correct it's because we force update URL while it's in downloading state.

New order:

  1. background thread: wrapper intercepts invocation to httpGet(), invokes listener.onIntercepted() and returns resource body.

in interception listener it posts Runnable to new handler (moving invocation to main thread (or even new background thread)) and returns immediately.

After it for that URL isDownloading is set to false

  1. Scheduled invocation in interception listener is invoked on main thread and it invokes ...filterEngine.updateFiltersAsync() and goes ahead. So we move ...filterEngine.updateFiltersAsync() invocation from the time moment when URL downloading=true to new time moment when downloading=false which forces actual downloading.
Last edited on 10/06/2017 at 10:52:53 AM by asmirnov

comment:15 in reply to: ↑ 14 ; follow-up: Changed on 10/06/2017 at 12:19:50 PM by sergz

Replying to asmirnov:
...

If i understand the problem correct it's because we force update URL while it's in downloading state.

That's right.

New order:

  1. background thread: wrapper intercepts invocation to httpGet(), invokes listener.onIntercepted() and returns resource body.

in interception listener it posts Runnable to new handler (moving invocation to main thread (or even new background thread)) and returns immediately.

It's still the same order, BTW, before that change it was posting it to a new background thread. Let's say the listener posts a Runnable to be executed in the main thread, right after that moment the background thread where the current httpGET is being executed pauses, the main thread processes that Runnable, the URL is still downloading, so the updating request is ignored, and afterwards the thread with httpGET can continue the execution. Before executing the Runnable mentioned above on has to ensure that the URL is removed from _downloading.

...

The approach in the review has the same drawback, and it does not change anything, however it seems the smallest one. The difference only in the delay, either a Runnable posted to the main thread or running it in a background thread as it was before will be likely executed too sooner than it's done currently.

comment:16 in reply to: ↑ 15 ; follow-up: Changed on 10/06/2017 at 12:44:39 PM by asmirnov

Replying to sergz:

Replying to asmirnov:
...

If i understand the problem correct it's because we force update URL while it's in downloading state.

That's right.

New order:

  1. background thread: wrapper intercepts invocation to httpGet(), invokes listener.onIntercepted() and returns resource body.

in interception listener it posts Runnable to new handler (moving invocation to main thread (or even new background thread)) and returns immediately.

It's still the same order, BTW, before that change it was posting it to a new background thread. Let's say the listener posts a Runnable to be executed in the main thread, right after that moment the background thread where the current httpGET is being executed pauses, the main thread processes that Runnable, the URL is still downloading, so the updating request is ignored, and afterwards the thread with httpGET can continue the execution. Before executing the Runnable mentioned above on has to ensure that the URL is removed from _downloading.

Got it, i forgot original invocation comes from bg thread, not from main thread.
It looks like we need URL queue within libadblockplus or even core..

I still don't like the solution with 300ms delay and i'd prefer to implement deferring properly: let's say have a list of deferred "URLs-to-update list", that is checked after each URL update is finished. Not sure how difficult is it to implement in core+libadblockplus.

...

The approach in the review has the same drawback, and it does not change anything, however it seems the smallest one. The difference only in the delay, either a Runnable posted to the main thread or running it in a background thread as it was before will be likely executed too sooner than it's done currently.

comment:17 in reply to: ↑ 16 Changed on 10/06/2017 at 01:35:51 PM by sergz

Replying to asmirnov:

I still don't like the solution with 300ms delay and i'd prefer to implement deferring properly: > let's say have a list of deferred "URLs-to-update list", that is checked after each URL update is finished. Not sure how difficult is it to implement in core+libadblockplus.

Well, I'm afraid there can be some other cancelling the updating request conditions, e.g. some comparison between expiration time, last successful and failure downloads, so I'm not sure yet how exactly it should be implemented, e.g. with some list of deferred download requests. However IMO, in general the support of preloaded subscriptions should be in the core, at the same level (at least in the same project) where all these things are. In addition there should not be any manipulations with URLs, like we extract a subscription URL by cutting parameters.

comment:18 Changed on 12/22/2017 at 12:31:28 PM by abpbot

A commit referencing this issue has landed:
Issue 5572 - fix stringBeginsWith in Util.cpp

comment:19 Changed on 10/23/2018 at 10:01:34 AM by asmirnov

  • Resolution set to fixed
  • Status changed from new to closed

Add Comment

Modify Ticket

Change Properties
Action
as closed .
The resolution will be deleted. Next status will be 'reopened'.
to The owner will be changed from sergz.
 
Note: See TracTickets for help on using tickets.