uBlockOrigin / uBlock-issues

This is the community-maintained issue tracker for uBlock Origin
https://github.com/gorhill/uBlock
945 stars 81 forks source link

InvalidStateError: A mutation operation was attempted on a database that did not allow mutations. #141

Closed daspri closed 6 years ago

daspri commented 6 years ago

Prerequisites

Description

Fails to update filters

A specific URL where the issue occurs

moz-extension://d879bf29-1bac-4212-8cbb-be53485d7ab0/dashboard.html

Steps to Reproduce

Open Firefox's "Browser Console" to see the error

  1. Go to Filter Lists
  2. Click 'Update Now'

Expected behavior:

Filters should update.

Actual behavior:

Filters do not update.

XHRGET https://raw.githubusercontent.com/gorhill/uBlock/master/assets/assets.json?_=212819
XHRGET https://publicsuffix.org/list/public_suffix_list.dat?_=212819
XHRGET https://raw.githubusercontent.com/uBlockOrigin/uAssets/master/filters/filters.txt?_=212819
XHRGET https://raw.githubusercontent.com/uBlockOrigin/uAssets/master/filters/badware.txt?_=212819
XHRGET https://raw.githubusercontent.com/uBlockOrigin/uAssets/master/filters/privacy.txt?_=212819
XHRGET https://raw.githubusercontent.com/uBlockOrigin/uAssets/master/filters/resource-abuse.txt?_=212819
XHRGET https://raw.githubusercontent.com/uBlockOrigin/uAssets/master/filters/unbreak.txt?_=212819
XHRGET https://easylist.to/easylist/easylist.txt?_=212819
15:53:46.412 [uBlock0CacheStorage] <unavailable>
vapi-cachestorage.js:94:9
genericErrorHandler
moz-extension://d879bf29-1bac-4212-8cbb-be53485d7ab0/js/vapi-cachestorage.js:94:9
XHRGET https://easylist.to/easylist/easyprivacy.txt?_=212819
[HTTP/2.0 200 OK 16ms]
15:53:46.993  InvalidStateError: A mutation operation was attempted on a database that did not allow mutations. vapi-cachestorage.js:230
putToDb/<
moz-extension://d879bf29-1bac-4212-8cbb-be53485d7ab0/js/vapi-cachestorage.js:230:17
getDb
moz-extension://d879bf29-1bac-4212-8cbb-be53485d7ab0/js/vapi-cachestorage.js:115:20
putToDb
moz-extension://d879bf29-1bac-4212-8cbb-be53485d7ab0/js/vapi-cachestorage.js:219:9
set
moz-extension://d879bf29-1bac-4212-8cbb-be53485d7ab0/js/vapi-cachestorage.js:77:9
onReady
moz-extension://d879bf29-1bac-4212-8cbb-be53485d7ab0/js/assets.js:533:9
getAssetCacheRegistry
moz-extension://d879bf29-1bac-4212-8cbb-be53485d7ab0/js/assets.js:426:9
assetCacheWrite
moz-extension://d879bf29-1bac-4212-8cbb-be53485d7ab0/js/assets.js:536:5
onRemoteContentLoaded
moz-extension://d879bf29-1bac-4212-8cbb-be53485d7ab0/js/assets.js:791:9
onLocalLoadSuccess
moz-extension://d879bf29-1bac-4212-8cbb-be53485d7ab0/js/assets.js:217:9
onLoadEvent
moz-extension://d879bf29-1bac-4212-8cbb-be53485d7ab0/js/assets.js:128:9

Your environment

uBlock Origin v1.16.14 Firefox 61.0.1 Windows 7 x64

gwarser commented 6 years ago

https://github.com/gorhill/uBlock/issues/2985

How much free disk space you have?

daspri commented 6 years ago

118,292,480 bytes free on that firefox drive

(browser.cache.disk.parent_directory is on a different drive with much more free space)

gorhill commented 6 years ago

Not much I will be able to do, apparently Firefox errors when uBO tries to write to the indexedDB.

If you search for firefox "A mutation operation was attempted on a database that did not allow mutations", you will find plenty of results. You may want to look into this. For example, did you set dom.indexedDB.enabled to false in about:config?

daspri commented 6 years ago

No, that setting is still set "true".

If I disable EasyList and restart firefox and Update Now, the update completes.

If I then Purge Cache and Update Now, it fails with the same error but after a different list (unbreak).

Briefly searching for this error mentions the dom.indexedDB.enabled setting (which I have set "true"), but results also suggest it can be caused by not waiting for an objectstore to be created before using it (async operations).

uBlock-user commented 6 years ago

Can't reproduce. Filters updating as expected. Reset Firefox settings to default(including the ones you set in about:config) and try again.

gwarser commented 6 years ago

118,292,480 bytes free

~120 megabytes? I have problems with filters update on my Android when free space is below ~350MB

gorhill commented 6 years ago

According to Browser storage limits and eviction criteria, the global limit is 50% of free disk space, so ~60 MB in the current case.

From this, there is a group limit, which if I understand correctly is that at most 20% of the global limit can by assigned to uBO, so 12 MB in the current case. So yes, it does seem like an issue with low disk space.

gwarser commented 6 years ago

@gorhill it is possible to detect this case and show some dialog?

gorhill commented 6 years ago

It's kind of a catastrophic error, the documentation said:

The group limit is also called the "hard limit": it doesn't trigger origin eviction

When this occurs, there is no fallback possible. This occurs deep in the code, when using Firefox API, and there might be no uBO UI available, aside the icon in the toolbar (assuming it has not been hidden by the user).

At this point, if I am going to throw lot of coding work at this, I rather work on the feasibility of compressing the data so as to reduce the storage footprint -- well it would be nice if Firefox's implementation of indexedDB did this for everybody.

At this point however, those suffering that sort of issue will have to free disk space. In the current case, ~120 MB is atypically low, regardless of uBO.

gwarser commented 6 years ago

When this happens filter lists are shown as outdated and when I click on "Update now" animation is spinning indefinitely - a way to fix only this case?

gorhill commented 6 years ago

when I click on "Update now" animation is spinning indefinitely - a way to fix only this case?

From what I see in the call stack above, this fails at the database level, not at the transaction level. There are error handlers at the transaction level. But it's a bit more complicated at the database level because the handlers at that level do not know about which callers need to be notified. It just means it's possible but not trivial to fix this. If I instead work on compressing (assuming feasability), this would possibly prevent uBO from failing (except in even more extreme cases of low disk space).

gwarser commented 6 years ago

I can reproduce after filling my disk by dd if=/dev/zero of=zero bs=1M and then updating filters:

Browser console log ``` 14:14:22.938 [uBlock0CacheStorage] abort ​ bubbles: true ​ cancelBubble: false ​ cancelable: false ​ composed: false ​ currentTarget: null ​ defaultPrevented: false ​ eventPhase: 0 ​ explicitOriginalTarget: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ isTrusted: true ​ originalTarget: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ srcElement: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ target: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ timeStamp: 1038957 ​ type: "abort" ​ : EventPrototype { composedPath: composedPath(), stopPropagation: stopPropagation(), stopImmediatePropagation: stopImmediatePropagation(), … } vapi-cachestorage.js:94:9 genericErrorHandler moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:94:9 (Async: EventHandlerNonNull) getDb/req.onsuccess moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:152:13 (Async: EventHandlerNonNull) getDb moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:149:9 vAPI.cacheStorage< moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:55:5 moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:41:22 14:14:23.104 [uBlock0CacheStorage] abort ​ bubbles: true ​ cancelBubble: false ​ cancelable: false ​ composed: false ​ currentTarget: null ​ defaultPrevented: false ​ eventPhase: 0 ​ explicitOriginalTarget: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ isTrusted: true ​ originalTarget: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ srcElement: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ target: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ timeStamp: 1039123 ​ type: "abort" ​ : EventPrototype { composedPath: composedPath(), stopPropagation: stopPropagation(), stopImmediatePropagation: stopImmediatePropagation(), … } vapi-cachestorage.js:94:9 genericErrorHandler moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:94:9 (Async: EventHandlerNonNull) getDb/req.onsuccess moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:152:13 (Async: EventHandlerNonNull) getDb moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:149:9 vAPI.cacheStorage< moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:55:5 moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:41:22 14:14:34.596 [uBlock0CacheStorage] abort ​ bubbles: true ​ cancelBubble: false ​ cancelable: false ​ composed: false ​ currentTarget: null ​ defaultPrevented: false ​ eventPhase: 0 ​ explicitOriginalTarget: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ isTrusted: true ​ originalTarget: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ srcElement: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ target: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ timeStamp: 1050616 ​ type: "abort" ​ : EventPrototype { composedPath: composedPath(), stopPropagation: stopPropagation(), stopImmediatePropagation: stopImmediatePropagation(), … } vapi-cachestorage.js:94:9 genericErrorHandler moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:94:9 (Async: EventHandlerNonNull) getDb/req.onsuccess moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:152:13 (Async: EventHandlerNonNull) getDb moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:149:9 vAPI.cacheStorage< moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:55:5 moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:41:22 14:14:34.628 [uBlock0CacheStorage] abort ​ bubbles: true ​ cancelBubble: false ​ cancelable: false ​ composed: false ​ currentTarget: null ​ defaultPrevented: false ​ eventPhase: 0 ​ explicitOriginalTarget: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ isTrusted: true ​ originalTarget: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ srcElement: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ target: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ timeStamp: 1050646 ​ type: "abort" ​ : EventPrototype { composedPath: composedPath(), stopPropagation: stopPropagation(), stopImmediatePropagation: stopImmediatePropagation(), … } vapi-cachestorage.js:94:9 genericErrorHandler moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:94:9 (Async: EventHandlerNonNull) getDb/req.onsuccess moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:152:13 (Async: EventHandlerNonNull) getDb moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:149:9 vAPI.cacheStorage< moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:55:5 moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:41:22 14:14:34.910 [uBlock0CacheStorage] abort ​ bubbles: true ​ cancelBubble: false ​ cancelable: false ​ composed: false ​ currentTarget: null ​ defaultPrevented: false ​ eventPhase: 0 ​ explicitOriginalTarget: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ isTrusted: true ​ originalTarget: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ srcElement: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ target: IDBTransaction { mode: "readwrite", db: IDBDatabase, error: DOMException, … } ​ timeStamp: 1050928 ​ type: "abort" ​ : EventPrototype { composedPath: composedPath(), stopPropagation: stopPropagation(), stopImmediatePropagation: stopImmediatePropagation(), … } vapi-cachestorage.js:94:9 genericErrorHandler moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:94:9 (Async: EventHandlerNonNull) getDb/req.onsuccess moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:152:13 (Async: EventHandlerNonNull) getDb moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:149:9 vAPI.cacheStorage< moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:55:5 moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:41:22 14:14:35.038 [Show/hide message details.] InvalidStateError: A mutation operation was attempted on a database that did not allow mutations. vapi-cachestorage.js:230 putToDb/< moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:230:17 getDb moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:115:20 putToDb moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:219:9 set moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/vapi-cachestorage.js:77:9 onReady moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/assets.js:533:9 getAssetCacheRegistry moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/assets.js:426:9 assetCacheWrite moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/assets.js:536:5 onRemoteContentLoaded moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/assets.js:791:9 onLocalLoadSuccess moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/assets.js:217:9 onLoadEvent moz-extension://a41ed17e-8cfa-48fa-8853-8be569753609/js/assets.js:128:9 ```
gorhill commented 6 years ago

I can reproduce after filling my disk

Isn't a scary thing to try? I fear the desktop/OS is going to start to fail badly before I can even get to try to repro.

uBlock-user commented 6 years ago

How is it a bug if you have to fill your hard disk just to reproduce it ? If your hard disk is at its limit, any software is expected to malfunction.

gorhill commented 6 years ago

Well the point is maybe uBO should at least stop spinning endlessly in its UI, though the core issue though would still be there: an essentially defect uBO because of low disk space.

gwarser commented 6 years ago

Isn't a scary thing to try?

:) @gorhill I have all Firefox test browsers as portable in home (partition) subfolder. And even for / there should be still space reserved for root user.

@uBlock-user this happens to me frequently on Android when my free disk space fall bellow ~350MB This is 2014 phone with only 4GB of disk space total and bellow 1GB for user. Updating apps may cause this and you will not even know when this happens until ads starts appearing. And you will not know why because there is no message, no browser console, just animation spinning. One time I left my phone with uBO Dashboard enabled for the night to check if something change.

gorhill commented 6 years ago

Ok I will come up with something. Since there is not always a UI available (ex. when auto-update kicks in, or selfie is taken, etc.), I am thinking of showing a red warning on the Settings page (where the "Storage used" area) for when the "mutation operation was attempted" error occurs -- which could be caused by other reasons than just low-disk space I suppose. That warning would be cleared whenever a write operation succeed.

daspri commented 6 years ago

My Firefox profile is on a virtual encrypted disk (vera/true) & portable, therefore not as large as the full drive. (cache is not on the same drive)

gorhill commented 6 years ago

when I click on "Update now" animation is spinning indefinitely - a way to fix only this case?

Looking at the code, I am not seeing why this would be. When uBO writes to the storage, it does so without minding the result. Are you sure about "indefinitely"? Can I see a screenshot of the console, I want to see if there is an unhandled exception, so far what I see is all handled by uBO.

gorhill commented 6 years ago

I can reproduce now. Found an old 1GB stick, created a new Firefox profile on it, and filled the stick with a 800MB file, there is around ~60 MB left. I get the errors now in the console, so now I have something to work with.

gwarser commented 6 years ago

One solution may be to go back to extension storage (should not have limits) - Mozilla will move backend to IndexedDB soon https://bugzilla.mozilla.org/show_bug.cgi?id=1474562 User will see low disk space before uBO starts to have problems.

Are you sure about "indefinitely"?

Yes, I even once leave phone for the night with it spinning.

gwarser commented 6 years ago

Screenshots

30 minutes later and still spinning.

gorhill commented 6 years ago

One solution may be to go back to extension storage

Using storage.local instead of indexedDB is irrelevant. If I want more disk space given to uBO, I need to add the unlimitedStorage permission.

So far I have resisted adding this permission because of how this was received by some users when Privacy Badger added it to their manifest .

In any case, now that I can reproduce I found out that there is an exception thrown, and this is trivially handled. uBO should still work fine without being able to use its cache (up to a point), this will just cause it to launch less efficiently since it might have to re-compile all filter lists every time.

The errors will still be written at the console, but there should no longer be unhandled exceptions.

uBlock-user commented 6 years ago

So far I have resisted adding this permission because of how this was received by some users when Privacy Badger added it to their manifest .

But you already added it in Chromium, and I don't see any backlash, so why would it now receive backlash for the same permission being added to Firefox?

gorhill commented 6 years ago

I think the unhandled exception that was fixed here could have been the cause of reports of uBO having 0/0 filters at launch. I selected EasyList DEU (not in the package) and I tested without the fix (installed from AMO), and the number of filters loaded was less than it should have been if all went fine. I then tested same with the fix here and all filters were loaded (probably took longer time though because they needed download/compilation).

gwarser commented 6 years ago

asset-viewer.html shows content from cache? Because EasyList shows Last modified: 12 Jun 2018 12:47 UTC

This may be version from package - regional list loads fine.

gorhill commented 6 years ago

asset-viewer.html shows content from cache?

By order: from cache, -- if not present, then from package, -- if not present then from remote location (if applicable).

gorhill commented 6 years ago

I experimented with the SnappyJS library, which pretty much fulfill what I would want from a compression algorithm for the current case: very fast, good enough compression. Here are the results:

                       raw      compressed   ratio  c-time  d-time (ms)
                     20675            5258     25%       9    
                     67263           27857     41%       7    
   ubo-filters      484933          157856     33%      15       6
                     13845            5520     40%       1    
                     61645           24427     40%       2    
      easylist     2693143         1095278     41%      47      23
   easyprivacy      421938          202465     48%      10       5
                     22754           14810     65%       1    
     malware-1      566422          382849     68%      17       7
         plowe       69313           26784     39%       2       3
compiled lists       66070           26063     39%       1       3
                     32748           15332     47%       1       2
                     43946           20443     47%       1       1
                     10588            4961     47%       0       0
                    640116          177965     28%       7       5
                    594705          282901     48%       9       6
                    795208          403235     51%      13       6
                   3626810         1419556     39%      48      34
       total-1    10232122         4293560     42%        

        selfie     4763264         2279030     48%      85      41
       total-2    14995386         6572590     44%        

  min disk space    143 MB           63 MB

Using Firefox's Gecko profiler, I find that the CPU overhead at load time is around 35-50 ms -- regardless of whether uBO loads from a selfie or not.

So now the question is, is it worth it to swap minus 8 MB of storage space and much lower min disk space for plus ~40 ms of load time? (assuming default lists).

Something to keep in mind is that even with the compression, there will always be a disk space threshold under which uBO will not work as expected, i.e. always falling back to use packaged lists rather than up to date ones.

grenzor commented 6 years ago

8 MB of storage space for plus ~40 ms of load time?

Did you mean 80MB? If so, it seems worth it to me.

Also did you look at https://github.com/lz4/lz4? Looking at their benchmarks it could be more efficient and provide better compression/decompression. Found some JS libraries for it on Github but not sure if they include the "LZ4 HC" version or comparable speed/efficiency of SnappyJS. Maybe you're already happy with SnappyJS but just thought I'd ask.

gorhill commented 6 years ago

Assuming default filter lists + selfie, without compressing, there need to be ~150 MB of free disk space, while with compressing there need to be ~70 MB of free disk space. The cache itself is ~15 MB uncompressed, ~7 MB compressed. I used min disk space = cache size x 5 x 2, as per indexedDB doc.

gwarser commented 6 years ago

You have SSD disk? Will be interesting to see load + decompress time on HDD. May be worth it for spinning disks or slow flash drives in phones (here depends on cpu but flash drives in phones may be way slower)

I mean, in best conditions, loading time for 100MB/s device for 20MB file compressed to 10MB should decrease time by 100ms, yes?

http://fastcompression.blogspot.com/p/compression-benchmark.html

gorhill commented 6 years ago

You have SSD disk?

Yes, I ran the benchmark from this. I could try benchmarking using the slowpoke 1 GB stick when time allow, you make a good point about factoring in storage speed when considering whether compression is worth or not. I am leaning toward worth it.

However I realized there was an obstacle yesterday: if I release a version of uBO supporting compression, than a user won't be able to go back to an earlier version of uBO not supporting compression. The problem arise with caching the raw filter lists, there is nothing in uBO to detect the way they are stored, it's always assumed to be stored as plain strings, so a earleir version of uBO dealing with compressed storage would end up with a Blob as filter list data instead of a string.

This is why I committed this yesterday, but then this means all versions of uBO 1.16.15b5 or less will break with cache generated by a future version of uBO supporting compression.

gorhill commented 6 years ago

Here are the results when using lz4-wasm:

                                      d-size      c-size  ratio   c-time ms   d-time ms
             [cache/assets.json]       20675        5517    27%           1    
        [cache/ublock-resources]       68524       29556    43%           1    
          [cache/ublock-filters]      500365      153737    31%           4
          [cache/ublock-badware]        5350        3085    58%           1    
          [cache/ublock-privacy]        7793        4440    57%           0
            [cache/ublock-abuse]       13929        5707    41%           0    
          [cache/ublock-unbreak]       63370       24706    39%           1    
                [cache/easylist]     2700655     1053468    39%          19    
             [cache/easyprivacy]      426307      203452    48%           3    
               [cache/malware-0]       22754       14641    64%           1    
               [cache/malware-1]      577440      364169    63%           7    
                 [cache/plowe-0]       69315       26129    38%           2    
 [cache/compiled/ublock-filters]      659064      179359    27%           4           2
 [cache/compiled/ublock-privacy]       11886        3065    26%           0           0
   [cache/compiled/ublock-abuse]       10611        5162    49%           0           0
 [cache/compiled/ublock-unbreak]       45121       20979    46%           0           0
       [cache/compiled/easylist]     3636161     1338516    37%          26          11
    [cache/compiled/easyprivacy]      599641      277396    46%           5           3
      [cache/compiled/malware-0]       32748       14779    45%           1           1
      [cache/compiled/malware-1]      811205      376090    46%           8           4
                        [selfie]     4808967     2200929    46%          45          19
                      Total (MB)        14.5         6.0    42%        

There were issues though with using WebAssembly:

So this means despite the promising results above, such wasm-based solution is not yet ready for a stable release. I may add experimental support through a hidden setting though, will see.

gwarser commented 6 years ago

Firefox: I needed to add application/wasm wasm to my /etc/mime-types

Why? Is https://gorhill.github.io/lz4-wasm/test/index.html different?

gorhill commented 6 years ago

I read the data through a XMLHttpRequest in the demo/benchmark page, and feed an ArrayBuffer to the WebAssembly engine. In the extension code I use WebAssembly.instantiateStreaming.

I actually did not try XMLHttpRequest in the extension code, I figure this would not be allowed because one could XMLHttpRequest to anywhere and use the bytes from the response to execute code from any origin -- so I stuck with the spirit of executing-code-only-from-the-package, anything else which would happen to work would quite certainly be an issue to fix in Firefox.

grenzor commented 6 years ago

Really interesting results!

Just out of curiosity, did node-lz4 have slower compression/decompression speeds than lz4-wasm? Also are the benchmarks using LZ4-HC equivalent settings or default/other?

gorhill commented 6 years ago

node-lz4 is included in the benchmark page.

lz4-wasm is the generic implementation of LZ4 block format, with hard-coded default, no HC there.

I simplified a bit the compressor implementation by not putting in code for detecting incompressible data, but even without this it's faster than node-lz4, and beside I wrote that code specifically for the purpose here and I do not expect that incompressible data is going to be an occurrence.

gwarser commented 6 years ago

My findings:

Looks like Firefox stores lots of nulls in database:

Size of .sqlite file (only) on my standard Nightly profile with latest uBO rc was ~40MB. After switch to lz4 branch (reset to default + restore backup) size decreased to 150kB - turned out most data is stored inside .files subfolder - only ~11MB! (with selfie)

I thought something is broken, but filter lists are recent and all seems to work fine.

I switched back to rc - .sqlite 41MB, .files 7MB.

Side note: storage.local is stored in second folder, with ^userContextId=* appended - ~70kB.

And I just confirmed this in fresh profile - lz4 branch uses ~11MB of disk space, latest rc 41MB of .sqlite and 7MB in .files without selfie, 12MB with selfie.

selectedFilterLists ``` "selectedFilterLists": [ "https://raw.githubusercontent.com/MajkiIT/polish-ads-filter/master/adblock_social_filters/adblock_social_list.txt", "https://raw.githubusercontent.com/MajkiIT/polish-ads-filter/master/cookies_filters/adblock_cookies.txt", "https://raw.githubusercontent.com/olegwukr/polish-privacy-filters/master/adblock.txt", "https://gist.githubusercontent.com/gorhill/ef1b62d606473c68d524/raw/f8181faac18cb5172c7c9bca8e5a3b22f0c925d0/gistfile1.txt", "POL-0", "plowe-0", "fanboy-social", "fanboy-thirdparty_social", "fanboy-annoyance", "adguard-annoyance", "malware-1", "malware-0", "fanboy-enhanced", "easyprivacy", "adguard-spyware", "easylist", "adguard-generic", "ublock-unbreak", "ublock-abuse", "ublock-privacy", "ublock-experimental", "ublock-badware", "ublock-annoyances", "ublock-filters", "user-filters" ] ```
jspenguin2017 commented 6 years ago

WOW, you actually coded the compression library in assembly?!

uBlock-user commented 6 years ago

Updated to the latest dev build, set cacheStorageCompression to true, purged all cache and redownloaded all my lists, storage size on Chromium was 27 megs(assuming this as the point of reference for comparison because FF doesn't support getBytesInUse API yet and now with the workaround in place) and now on Firefox it's 9.9 megs!! Impressive!

yourduskquibbles commented 6 years ago

I am showing a 3X size reduction as well, storage size was 15megs and is now 5megs with cacheStorageCompression set to true. Great work!

gwarser commented 6 years ago

Correction (update) to my comment about database size - my Nightly finally decided to put something inside .sqlite file. Now it's .sqlite: 16MB, *.files: 12MB uBO reports: Storage used: 16,277,060 bytes

No idea why this happened - I cannot reproduce in fresh profile...

gorhill commented 6 years ago

Sounds like the load selfie to me. Note that when you enable cacheStorageCompression, uBO will compress opportunistically from there on, it will not go through the storage to compress existing entries, just when something is written to it. If you want to find out the difference after toggling the setting, purge all caches and force an update. Also, eventually the selfie will be also written to the storage after all filter lists are updated,

ghost commented 6 years ago

Changed setting "cacheStorageCompression" to true, then went to purge and finally added my lists, before 11 megs and now 4 megs (close to 3x size reduction!), using Firefox 62 Beta on Android, works!

gorhill commented 6 years ago

I used the Gecko profiler to find out how compression affects load time of uBO. I measured with a selfie available (which I consider the most likely scenario for majority of users). Tested using a desktop computer with an SSD drive.

I repeated the disabling/enabling of uBO three times in the profiler, with enough time in between to ensure clearly separate instances in the profiler. I filtered out the profiler output using moz-, uBO was the only extension installed.

As a result there were three clear regions of CPU usage, corresponding to uBO being launched and doing its work to load everything in memory. I then focused the profiler timeline to match exactly the start and end of each of those regions, using the magnifier to increase the granularity until the timeline was matching exactly the start/end of uBO doing its launch work. This allowed me to find out the length in time of the focused region.

This is the results:

Those figures indicates that despite the added overhead of having to lz4-decode the loaded data, uBO loaded faster. In the Gecko profiler results, I could definitely see an area of idleness in the middle which has been shrunk when using compression, enough to gain faster load despite the lz4-decoding overhead. Below are comparative screenshots, you can see the area of idleness in the middle being reduced when compression is used (bottom graph):

a

gwarser commented 6 years ago

there were three clear regions of CPU usage

Not sure if you know this, these blue "hills" in the graph are not cpu usage. This is stack size. Even low "height" may use lot of cpu.

https://perf-html.io/docs/#/./guide-ui-tour?id=timeline39s-thread-stack-graph

uBlock-user commented 6 years ago

There's a performance-wise gain too when force updating filterlists, previously it would take a second or two for it to complete, now it downloads and updates the lists instantaneously and snappier even on Chromium.

gorhill commented 6 years ago

The original issue has been addressed, the compression won't ever guarantee that running low on disk space will never affect uBO, so at this point I consider the issue fixed.

shellye5 commented 6 years ago

@gorhill sometimes filters take long to download with compression on any ideas on how to debug it? Are you enabling it soon? will this come to legacy too?

Vangelis66 commented 6 years ago

... Apologies if this isn't the proper place to post about my predicament, but I was directed to this issue via the Release Notes of the latest dev build...

OS: Windows Vista SP2 32-bit Browser: Mozilla Firefox ESR 52.9.0 32-bit uBlockOrigin version: dev channel, v1.16.21b0 (WE)

I was updated to the latest dev build from a previous dev build (from memory, must've been 1.16.17.7) which is now removed from the GitHub repo.

I opened the dashboard and tried to manually update 3rd-party filters; the "clocks" at the far right of each list all started spinning but after a few (3-4) seconds all turned simultaneously into an orange triangle (with a white exclamation mark inside), then, after another 2-3 seconds, all went back into the "clock" state...

This behaviour I had never witnessed previously, after some checks it looked as though my lists hadn't updated 😭 E.g., the "I don't care about cookies" list remained at v2.8.8, while I checked and v2.8.9 is already on line at its site...

From looking closer at the release notes of 1.16.21b0, I saw

A new advanced setting: cacheStorageCompression, default to true. When true, uBO will lz4-compress data before storing it in its cache storage in supported platforms. Currently, the only supported platform is Firefox/Firefox for Android.

By launching Firefox Browser Console (CTRL+SHIFT+J), clearing everything inside it and starting a manual 3rd-party filter list update, the console is populated with many Error: LZ4BlockWASM: not initialized instances:

brconsole

I do hope they're meaningful to someone of you wonderful people...

For now, my options to successfully update 3rd-party filter lists on my setup are tested to be:

  1. Access "advanced user" settings, toggle the new pref cacheStorageCompression to false, apply changes and then the update of lists will work...
  2. Downgrade to the latest version (1.16.20=1.16.18) of the stable channel, where cacheStorageCompression is either absent/not enabled by default.
  3. Downgrade to the latest legacy (XUL) version, 1.16.4.4, installable on 52.9.0 - sadly, it isn't backwards compatible with the WE versions, hence I'd have to reconfigure it from scratch...

I understand that I don't have things on my side, as Vista has been EOL'd by MS and Fx 52.9.0 will be EOL'd by Mozilla in over a week's time... However, any insight as to what's the cause of this new issue will be highly appreciated...

Many thanks in advance....