Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Database first upload issue #73

Closed
uberneko opened this issue Nov 23, 2018 · 13 comments
Closed

Database first upload issue #73

uberneko opened this issue Nov 23, 2018 · 13 comments

Comments

@uberneko
Copy link

Hello !
Discovered that project on reddit protonmail - sounds really great -
Using the 2.0-beta7 with Appimage on a *buntu 18.04 - only on a protonmail (free) account.

When switching to the database mode, it will say 'data loading' for some time (3 min ?) and will eventually send an error message: "Invocation timeout of "buildDbPatch" method on "email-securely-app:webview-api" channel".
I think it even sends this message when being on online mode after a while (does it try to download the db in background ?)
Worth mentioning that my emails are about 350Mo in Protonmail... 3mins may not be enough anyway. I didn't see any database.bin file created.

@vladimiry
Copy link
Owner

vladimiry commented Nov 24, 2018

Ok, first of all, to make things clear. There is no first upload, but download. I used to name the initial load bootstrap fetch. The app doesn't upload anything, but only downloads stuff, so one way syncing.

my emails are about 350Mo

This is going to be a serious test for the local store feature. Do you know how many emails there approximately? I guess attachments might occupy a significant portion of the used space.

2.0-beta7

Are you sure you run beta 7? Starting from beta 7 local store syncing timeout (fetching timeout) is configurable and the default value is set to 10 minutes. Is there the following options block in your config.json file?:

    "fetchingRateLimiting": {
        "intervalMs": 60000,
        "maxInInterval": 250
    },
    "timeouts": {
        "fetching": 600000
    }

600000 milliseconds here is equal to 10 minutes.

Consider adjusting the following values in config.json (requires app restart):

  • Setting logLevel to verbose.
  • Increasing the timeouts.fetching.

You can also if you want to increase the maxInInterval value to something like maybe 300+ in order to speed things up a little. Doing that you might end up with Too Many Requests error as we still don't know what is the optimal value. Keep the 250 value in case of such error as it seems to be a safe value.

Please make sure that app doesn't perform the bootstrap fetch for more than one protonmail account in the same time (add one account, wait for bootstrap fetch completion, add the second account ...). Parallel bootstrap fetch running doesn't yet work well enough, will later consider improving it.

The log file is going to be huge and messy. There will be for example records containing the constantly updated rateLimitedMethodsCallCount value, this is how many rate-limited requests app processed at the moment.

Can you also calculate based on the log file or using timer what is the actual time of getting the error starting from bootstrap fetch running? 😄

I think it even sends this message when being on online mode after a while (does it try to download the db in background ?)

The app is supposed to automatically keep the database up to date, so yes it does some fetching in the background, but those are diff only fetching, not so massive load as the initial/bootstrap fetch. The only way to stop fetching is disabling the local store feature for the account (it's disabled by default).

I didn't see any database.bin file created.

There will be no database.bin until bootstrap fetch successfully completed. After that app will execute the diff requests only, means no more massive fetching.

If you get the bootstrap fetch successfully completed I'd be interested to know what is the database.bin file size and main process memory use. App keeps the full database in memory while the app is running 😄

@uberneko
Copy link
Author

Hello - thank you for the feedback -
My bad - yes indeed I meant download. 350Mo will be challenging I concur... How many emails ? No clear idea - but there are attachments for sure - something like 1200 emails maybe.

I do confirm it is 2.0-beta7 - the file I execute is "email-securely-app-2.0.0-beta.7-linux-x86_64.AppImage" plus I confirm the options block in my config.json file:

"fetchingRateLimiting": {
    "intervalMs": 60000,
    "maxInInterval": 250
},
"timeouts": {
    "fetching": 600000
}

I have put "Setting logLevel" to "verbose" and increased timeouts.fetching to 1200000. I kept maxInInterval at 250. I use the app just for one single protonmail account.

It took about 20mins until it failed (I used a timer), with same error message. I can't see something really interesting in the log file.

Just in case - when the app runs, I see those processes:

  • email-securely - about 370Mo
  • AppRun (with the app logo in green) - about 160 Mo
  • another email-securely - about 130Mo

Now I understand that the massive download of the database occurs once - but if it fails, it will try from the beginning each time I switch to database view mode again. I wonder how protonmail servers consider this massive and sudden request..

Oh.. and the AppImage version takes something like 45s to be operationnal (once you've cliked on it) .. ? Is that normal ? (checking it on a J1900 processor though - PassMark benchmark multi thread 1851 / single thread 535).

@vladimiry
Copy link
Owner

It took about 20mins until it failed (I used a timer)

increased timeouts.fetching to 1200000

Given these points, it's now confirmed that configurable timeout actually takes place since 1200000 milliseconds = 20 minutes. It's a good thing to know.

Considering the maxInInterval=250 (request limit per minute), we can assume that the app was able to process about 5000 requests in 20 minutes. 5000 value doesn't necessarily reflect the emails count since app also executes other types of requests (like fetching conversations, labels, etc), maybe up to 10% side requests. If the 10% side requests amount guess is accurate enough, then we can assume that you have got more than 4500 emails.

I can't see something really interesting in the log file.

I guess if you scan the log.log file from the bottom upwards using the rateLimitedMethodsCallCount as the search keyword, you will see that rateLimitedMethodsCallCount value is close to 5000. Can you take a look?

Oh.. and the AppImage version takes something like 45s to be operationnal

AppImage is a compressed thing and starting it takes some time even on a more performant machines than you got. I think it's ok to run AppImage package trying a beta releases, but when stable v2 gets released you can just install a normal package (deb package since you run Ubuntu).

I suggest to do the following (requires app restart):

  • Set timeouts.fetching to 3600000 (60 minutes) or better jump straight to 10800000 (180 minutes / 3 hours) 😄
  • You can also if you want increase the maxInInterval value to something like maybe 300 in order to speed things up a little. Doing that you might end up with Too Many Requests error as we still don't know what is the optimal value. Keep the 250 value in case of such error as it seems to be a safe value.

@uberneko
Copy link
Author

Ok, today's test failed again but here are some observations -

I have set timeouts.fetching to 3600000 (60 minutes) and maxInInterval value to 275.

Regarding log file, the max in the first test was "rateLimitedMethodsCallCount" 3036 (yesterday). It went up to 6161 today.

It indeed lasted 60mins until I get the error message. Worth mentioning that up to 32min, I had an email-securely growing process taking about 1.5Go of ram at the end - then it suddenly disappeared leaving a new (or not noticed before) email-securely-app--type=gpu-process --no-sandbox (...) process taking half of cpu at least.

Nothing interesting in the log from those 32min to 60min.

I stupidly didn't open the System Monitor at the beginning to check the download rate and total amount of download - it was at 90Mo when I realized I should have done it, but I opened the System Monitor very late. I'll check it a next time totally, though I did relaunch a db download for some minutes, the download is quiet, about 40-50 ko/s - sometimes a few seconds at 0, sometimes a peak at 100ko/s - but there are breaks quite often [my connection allows 1.2Mo/s].

@vladimiry
Copy link
Owner

vladimiry commented Nov 25, 2018

Thanks for the detailed report, it helps in making the app work better.

So far it looks like app works properly and you are doing everything right, just increase the timeouts.fetching to 10800000 (180 minutes) or even further (really, make it bigger).

I have set timeouts.fetching to 3600000 (60 minutes) and maxInInterval value to 275.

So it's now confirmed that 275 is a new safe timeouts.fetching value. Going to update the default configuration (250 => 275), so bootstrap fetch thing will take a little less time for completion.

the download is quiet, about 40-50 ko/s - sometimes a few seconds at 0, sometimes a peak at 100ko/s - but there are breaks quite often [my connection allows 1.2Mo/s].

The download is not supposed to be constant, but more like constantly interrupted process. It's by design since we need to tackle the rate limiting restriction Protonmail has put to its API. So basically what you did by setting the fetchingRateLimiting.maxInInterval value to 275 is allowed to the app execute no more than 275 requests per minutes. So you can imagine why the bootstrap fetch process looks like working very slowly, it's because Protonmail itself doesn't allow us to execute unlimited fetching.

@uberneko
Copy link
Author

Ok - I did think I had some time this morning, so I ran a test - but I had to stop at 1:02:00, but I think there is an issue anyway:
I've put timeouts.fetching to 10800000.

At 00:00:00:
around 40% cpu usage
0Mo downloaded

Around 00:25:00 it stopped at 70.9Mo downloaded - nothing more - times to times a 'peak' at 4ko/s but for 1sec... I assume it is the OS, not the app (or Firefox was open but kept in background, not used).

Around 00:27:00
sudden increase to 100% of load cpu usage
70.9 Mo downloaded

00:35:00
cpu usage back to 40%
70.9 Mo downloaded

00:47:00
cpu usage still at 40%
70.9Mo downloaded

1:00:00
cpu usage still at 40%
71.0 Mo downloaded

Overall memory usage did climb from about 1Go I'd say. So as a summary, it downloaded about 70Mo at an average 50ko/s during 25mins and then stopped.

Also worth mentioning that after the test (it did that in the previous test on Sunday actually) when switching back from database mode to 'online' mode - there is a black window - the protonmail web app is not displayed anymore.

@vladimiry
Copy link
Owner

vladimiry commented Nov 28, 2018

Overall memory usage did climb from about 1Go I'd say. So as a summary, it downloaded about 70Mo at an average 50ko/s during 25mins and then stopped.

Would be interested to see the rateLimitedMethodsCallCount value form the log file, is it bigger than 6161 (the value you stopped with last time)? And what was the start time value when rateLimitedMethodsCallCount changed last time, like around 00:25:00 or it kept increasing until 1:02:00 despite the low network load?

Also, consider sending log file to the email address specified here.

when switching back from database mode to 'online' mode - there is a black window - the protonmail web app is not displayed anymore.

Would be interested in seeing a screenshot of that black window. So far I just have a guess that it might be due a low-performance computer. I can't reproduce the issue in my own at the moment since I don't have an account with a huge emails base.

@uberneko
Copy link
Author

The rateLimitedMethodsCallCount went up to 6170. And it was indeed at my "around 00:25:00", which was in reality "2018-11-28 10:26:49.099". From this time to 1 hour, the log is quite empty actually...
Ok I'll send the log.
Next time I try, I'll make a screenshot of the black window.

@Forsaked
Copy link

Forsaked commented Dec 3, 2018

I had the same issue, but since 2.0.0 beta 8 it doesn't happen to me anymore.

@vladimiry
Copy link
Owner

I've been communicating with @uberneko privately. Beta 8 release included some adjustments as a result of this communication. Besides I'm going to tweak fetching/persistence logic one more time soon.

@Forsaked thanks for the input, do you mind sharing some information (don't have to, or consider answering privately to this email)?:

  • How many emails you got there (you can see the total count value in database view mode, or in log file, but it's more complicated)?
  • database.bin file size.
  • Does the database view mode work for you (you can navigate there, export the messages, etc)?

@Forsaked
Copy link

Forsaked commented Dec 3, 2018

@vladimiry i will check this when i am home.

  1. i've got 2449 emails there
  2. the database.bin size is 86MB
  3. yes, database view works and export also (2441 of 2449 emails got exported)

@uberneko
Copy link
Author

uberneko commented Dec 7, 2018

Issue solved with beta9 build "https://www.dropbox.com/sh/t8emnmv0g5ypahm/AADjhplGXInGsNUNAIeZ2nhra?dl=0&lst=" !
(12/6/2018 3:52 pm)
Thanks a lot for your support -
(database.bin size 175Mo - about 6100 emails)

@vladimiry
Copy link
Owner

Improvements have been implemented to solve the issue:

  • Added configurable fetching timeout, defaults to 60 minutes.
  • Enabled batch processing for the bootstrap fetch operation with configurable minimal portion size, defaults to 500. Without batch processing browser was crashing in the case of huge email messages list processing. This feature is enabled for protonmail accounts only as for now.

New release is coming shortly.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants