Closed roydok closed 4 years ago
@roydok Thank you for your bug report. Can you give one example of a search which takes two minutes to give results? Same question for a search giving no result at all?
Hi. Thank you very much for your quick reply. I tried moving the 35.8 gb off-line Wikipedia file from the 512 gb microSD card to my 128 gb internal storage. The search speed improved but still slower compared to the older Kiwix version 2.5. The older Kiwix version 2.5 has a fast search and search suggestion if your file is located in either the microSD card or internal storage. The current Kiwix version 3.3.1 only does fast search if the file is in the internal storage but super slow to no search in the microSD card. I am going to keep my file in the internal storage until this is improved.
Thank you again.
On Tue, May 12, 2020, 1:53 PM Kelson, notifications@github.com wrote:
@roydok https://github.com/roydok Thank you for your bug report. Can you give one example of a search which takes two minutes to give results?
— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/kiwix/kiwix-android/issues/2082#issuecomment-627125755, or unsubscribe https://github.com/notifications/unsubscribe-auth/APRPGMOHGJVFATI4YLHBU23RRDP3XANCNFSM4M6NAE7A .
@roydok This is great if it works better for you. That said, without clear and precise reproduction steps, we won't be able to work on this ticket and will close it.
I could maybe build an apk which is 2.5.0 but with latest kiwixlib and see if the slowdown is a result of kiwixlib or if it is the android app?
Otherwise I don't know how to diagnose this. Could it also be the age of the file? 32 gb Wikipedia off-line
, knowing the date of this file wouldn't hurt anyways.
With a 2018-07-01 Wikipedia 77.2GB search is near instantaneous for me on a Galaxy Tab S running 6.0.1.
@roydok could you send a diagnostic report? The functionality can be found in the help screen of the app.
@macgills I strongly suspect this was at a time and with a ZIM file without a title Xapian index. This is why I ask for a concrete up2date use case. I don't think this make sense to come back to 2.5.
Diagnostic sent as you requested. I transfered back the 35.8 gb off-line Wikipedia file back to my 512 microSD card and ran Kiwix version 3.3.1 doing the search and generating the diagnostic as you suggested. Search is still slow.
On Tue, May 12, 2020, 11:16 PM Seán Mac Gillicuddy, < notifications@github.com> wrote:
I could maybe build an apk which is 2.5.0 but with latest kiwixlib and see if the slowdown is a result of kiwixlib or if it is the android app?
Otherwise I don't know how to diagnose this. Could it also be the age of the file? 32 gb Wikipedia off-line, knowing the date of this file wouldn't hurt anyways.
With a 2018-07-01 Wikipedia 77.2GB search is near instantaneous for me on a Galaxy Tab S running 6.0.1.
@roydok https://github.com/roydok could you send a diagnostic report? The functionality can be found in the help screen of the app.
— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/kiwix/kiwix-android/issues/2082#issuecomment-627409790, or unsubscribe https://github.com/notifications/unsubscribe-auth/APRPGMJ6FNFRFITR2LCZATTRRFR3VANCNFSM4M6NAE7A .
Diagnostic sent
On Tue, May 12, 2020, 11:57 PM Roy Concepcion, roydok9111976@gmail.com wrote:
Diagnostic sent as you requested. I transfered back the 35.8 gb off-line Wikipedia file back to my 512 microSD card and ran Kiwix version 3.3.1 doing the search and generating the diagnostic as you suggested. Search is still slow.
On Tue, May 12, 2020, 11:16 PM Seán Mac Gillicuddy, < notifications@github.com> wrote:
I could maybe build an apk which is 2.5.0 but with latest kiwixlib and see if the slowdown is a result of kiwixlib or if it is the android app?
Otherwise I don't know how to diagnose this. Could it also be the age of the file? 32 gb Wikipedia off-line, knowing the date of this file wouldn't hurt anyways.
With a 2018-07-01 Wikipedia 77.2GB search is near instantaneous for me on a Galaxy Tab S running 6.0.1.
@roydok https://github.com/roydok could you send a diagnostic report? The functionality can be found in the help screen of the app.
— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/kiwix/kiwix-android/issues/2082#issuecomment-627409790, or unsubscribe https://github.com/notifications/unsubscribe-auth/APRPGMJ6FNFRFITR2LCZATTRRFR3VANCNFSM4M6NAE7A .
@roydok interesting.... your sdcard reports its filesystem as sdfat which I believe should not support files of this size.
Thank you very much.
On Wed, May 13, 2020, 12:00 AM Roy Concepcion, roydok9111976@gmail.com wrote:
Diagnostic sent
On Tue, May 12, 2020, 11:57 PM Roy Concepcion, roydok9111976@gmail.com wrote:
Diagnostic sent as you requested. I transfered back the 35.8 gb off-line Wikipedia file back to my 512 microSD card and ran Kiwix version 3.3.1 doing the search and generating the diagnostic as you suggested. Search is still slow.
On Tue, May 12, 2020, 11:16 PM Seán Mac Gillicuddy, < notifications@github.com> wrote:
I could maybe build an apk which is 2.5.0 but with latest kiwixlib and see if the slowdown is a result of kiwixlib or if it is the android app?
Otherwise I don't know how to diagnose this. Could it also be the age of the file? 32 gb Wikipedia off-line, knowing the date of this file wouldn't hurt anyways.
With a 2018-07-01 Wikipedia 77.2GB search is near instantaneous for me on a Galaxy Tab S running 6.0.1.
@roydok https://github.com/roydok could you send a diagnostic report? The functionality can be found in the help screen of the app.
— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/kiwix/kiwix-android/issues/2082#issuecomment-627409790, or unsubscribe https://github.com/notifications/unsubscribe-auth/APRPGMJ6FNFRFITR2LCZATTRRFR3VANCNFSM4M6NAE7A .
My microSD card is a Samsung Evo plus 512 gb. I used it as is and not reformatted it. I'll transfer the large 35.8 gb file back to the main internal storage to have a faster search in Kiwix version 3.3.1. Thank you very much for your time.
On Wed, May 13, 2020, 12:10 AM Seán Mac Gillicuddy, < notifications@github.com> wrote:
@roydok https://github.com/roydok interesting.... your sdcard reports its filesystem as sdfat which I believe should not support files of this size.
— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/kiwix/kiwix-android/issues/2082#issuecomment-627441564, or unsubscribe https://github.com/notifications/unsubscribe-auth/APRPGMPFX2XG3TZMU3WSMRLRRFYG5ANCNFSM4M6NAE7A .
If you can reformat to exfat the sdcard I would recommend that? Honestly it shouldn't have been able to copy the files over at all if the filesystem does not support files of this size. We could have a flaw in our methodology for detecting filesystems, very few pieces of code are perfect.
I'll try to reformat the card tom and report back to you and send you the diagnostic. Thanks again for your help.
On Wed, May 13, 2020, 12:15 AM Seán Mac Gillicuddy, < notifications@github.com> wrote:
If you can reformat to exfat the sdcard I would recommend that? Honestly it shouldn't have been able to copy the files over at all if the filesystem does not support files of this size. We could have a flaw in our methodology for detecting filesystems, very few pieces of code are perfect.
— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/kiwix/kiwix-android/issues/2082#issuecomment-627444579, or unsubscribe https://github.com/notifications/unsubscribe-auth/APRPGMJDOEUYY4YHLNAK2HDRRFY3BANCNFSM4M6NAE7A .
Thank you for helping diagnose the problem, hopefully we can improve kiwix.
@roydok @macgills What is the status here? How does it work with ve rsion 3.3.2 in beta an a recent ZIM file?
We have greatly improved performance with thread safe searches and also helped the memory footprint by disposing unused readers used for searching. I was never able to replicate 2 min searches as the search results appeared almost instantaneously for me
@macgills Those improvements that you mentioned were introduced in which version?
I am running v3.3.3 Build: 5230303 on my tablet and search is unbearably slow with the new wikipedia_en_all_maxi_2020-06.zim
. By comparison, v2.5 and the 2016 English Wikipedia maxi, that I upgraded from, searched instantaneously.
After typing in "faceboo" it takes the app 20-25 seconds to return a list of results, which makes the app painful to use. Recently, another user described having the same issue.
What's interesting is that, after this initial delay, deleting characters from the end or appending characters updates the results far quicker (a second or 2 at most). This makes me wonder whether KiwiX is doing some sort of unnecessary, exhaustive searching upfront rather than solely focusing on getting results that start with "faceboo".
@dbedrenko 3.3.3 includes our latest fixes to search and the latest version of kiwixlib.
I will attempt to reproduce the issue on my tablet but this will take a while as the download is quite large, right now it reports as 4 day left
.
I think this issue is related to the zim file but @kelson42 may be able to speak with more clarity there.
I'm not able to reproduce the problem with my Google Pixel2. I believe the ZIM file to be correct. For the moment, I have actually no clue why on a few devices the search is that slow.
With the Pixel2 I doubt it has a sd card which seems to be a key component in this issue.
Yes, the problem is that Kiwix is very slow to search a recent ZIM file on an SD card - even when the SD card is high-speed.
Do let me know if I can help debug somehow. I have a rooted device, so you could give an .apk with whatever debug messages would be helpful to you. I could then upload this log file.
If it is not too difficult I could also access the device with a debugger? Via AndroidStudio or whatever (I'm not familiar with this environment). Not sure if this would be helpful, offering just in case.
Thank you very much for the offer but I think raw log inspection may not be very helpful unless I were to deliver you a version with enhanced search logging. I may yet do that and take you up on the offer if my own attempts to recreate the problem are fruitless.
Depending on your code/kotlin literacy I would invite you to look at SearchResultGenerator if you want an indepth understanding of the code.
@macgills What might be great here to know is if the process get stuck inside or outside the libkiwix.
I have been unable to replicate on my tablet Galaxy Tab S SM-T700 Android 6.0.1 with Wikipedia Maxi 88.5GB 2020-06-26
On the very first search I did experience some delay but I would say more in the region of 5 seconds before results appeared and all subsequent searches were fine. @kelson42 is the some index building process on initial search?
@macgills My UX is similar and is not coherent with the bug report which is more about 60s. The first search needs a bit of I/O, this is the best explanation I have for the moment. Nothing different otherwise in term of processing.
I can make a version with logs for @dbedrenko to help us identify the bottleneck but it may be tomorrow with the PRs on my plate
I can make a version with logs for @dbedrenko to help us identify the bottleneck but it may be tomorrow with the PRs on my plate
Take your time, I will be on holiday until Tuesday (and thus unavailable).
Thanks a lot for trying to help the users that DO have this issue! :)
Here is some example output of me searching for "a"
And here is a link to the apk: https://drive.google.com/file/d/1ekCGG8xoR4jXI33Ll35RrWrVK2sM-lWB/view?usp=sharing
Enjoy your holidays and let me know if you encounter any problems
@macgills Attached is the output from the point I begin typing "facebo"
The big "Search Suggestion" output is outputted all at once about 15-20 seconds since I began typing. The search results display on screen about ~8 seconds after that.
top
displays the kiwixmobile
to be the top process throughout, at ~47% CPU. What's noteworthy is that the sdcard
process is not to be seen (but it was top process when the app was scanning for the .zim file in the Library screen.)
Please let me know if I can do any more debugging, would be happy to help.
Thank you for the logs. It would be handy if I could get timestamps in the logs, did you get these from the logcat file in the kiwix directory or run logcat yourself?
I wonder if you would get faster results from typing faster, we only submit a term to the results generator if there hasn't been another key entered within 500ms of another key
E/SEARCH_BUG( 5505): about to call searchSuggestions for fa on RxCachedThreadScheduler-9
E/SEARCH_BUG( 5505): about to call searchSuggestions for f on RxCachedThreadScheduler-14
E/SEARCH_BUG( 5505): about to call searchSuggestions for face on RxCachedThreadScheduler-13
E/SEARCH_BUG( 5505): about to call searchSuggestions for faceb on RxCachedThreadScheduler-12
E/SEARCH_BUG( 5505): about to call searchSuggestions for facebo on RxCachedThreadScheduler-22
and as seen here we are operating 5 searches simultaneously in separate threads
Thank you for the logs. It would be handy if I could get timestamps in the logs, did you get these from the logcat file in the kiwix directory or run logcat yourself?
I ran logcat via adb
, didn't know there was a log file being created somewhere. Not sure how to get this with timestamps...
I wonder if you would get faster results from typing faster, we only submit a term to the results generator if there hasn't been another key entered within 500ms of another key
I made it a point to type with good speed (still using one hand as usual though).
and as seen here we are operating 5 searches simultaneously in separate threads
If searches do not depend on preceding searches, what is the benefit of continuing to fetch the results for "f", "fa", "fac", "face" e.g. at the point in time when the user has entered "faceb"? When the user has entered "faceb" I don't think that they want to see the results for "f" or "fa", etc.
Maybe we should cancel those searches?
and as seen here we are operating 5 searches simultaneously in separate threads
If searches do not depend on preceding searches, what is the benefit of continuing to fetch the results for "f", "fa", "fac", "face" e.g. at the point in time when the user has entered "faceb"? When the user has entered "faceb" I don't think that they want to see the results for "f" or "fa", etc.
This remark seems absolutly pertinent to me. On Kiwix-Desktop for Linux/Windows we stop "old" threads before starting one and I thought we had fixed this a few months ago on Kiwix-Android honestly.
https://drive.google.com/file/d/10LPnhWsW11lwTQGbLTKBeJ4HkZXwSxrn/view?usp=sharing here is a version with task cancellation.
it doesn't have the logging in it though so it is a very much "see if it works", for future reference logcat format is controlled with a -v
option link
The task cancellation was much uglier code and didn't seem necessary during my testing of fixing the bug of the search results from the reader not being thread safe. I still feel like we are not addressing a core issue because of not being able to reproduce this consistently across devices but if this fixes it then it fixes it.
Thank you for the second build, but unfortunately it is still very slow (although it's faster).
Attached is the log for the first debug build, now with timestamps: first-debug-build-with-time.log
And the log from the new debug build that cancels old searches: debug-build-cancel-searches.log
Do you see anything that hints at in which operation most of the time is being spent?
@dbedrenko Thank you for keeping testing and helping us to fix the problem. I still believe that somehow there is chance that part of the problem comes from the SD card or the SD card reader. If I understand properly, the Samsung Galaxy S20 Ultra is a really high end device with the lot of internal memory. I would really be interested to know how it works if the ZIM is stored on the internal memory. @macgills I would recommend to have a look to both ticket/PR of https://github.com/kiwix/kiwix-desktop/issues/265. Similar problem/solution for Kiwix-Desktop and now it works like a charm.
I would really be interested to know how it works if the ZIM is stored on the internal memory.
@kelson42 Unfortunately, my tablet doesn't have such a large internal storage so I cannot try this. As mentioned previously, while the search is happening the sdcard
process is not using CPU like it was when scanning the storage card for a .zim file. The CPU was all used up in the kiwix process. This sounds to me like searching is CPU-bound rather than IO-bound.
07-17 21:16:43.914 E/SEARCH_BUG(22157): received search term g
07-17 21:16:44.414 E/SEARCH_BUG(22157): sending g to result generator
//500 ms delay completely expected
07-17 21:16:51.695 E/SEARCH_BUG(22157): about to call searchSuggestions for g on RxCachedThreadScheduler-4
//7 second delay here, note RxCachedThreadScheduler-4 indicating we absolutely are on a background io thread before calling kiwixlib
07-17 21:17:19.937 E/SEARCH_BUG(22157): result of searchSuggestions for g is true
//28 second delay to get a result from kiwixlib
07-17 21:17:30.453 E/SEARCH_BUG(22157): found suggestion SearchSuggestion(title=Ge, url=/A/Ge)
// results start coming in 10 sec later
so the delay is largely in kiwixlib, it might be beneficial to add logging to the task cancellation apk if you are still willing to test @dbedrenko but this may be tomorrow as I have a good few tickets to get to today.
It is quite technically challenging but in Android Studio there is a Profiler that can be run to collect CPU usage data, I am not too familiar with it and native code but it could offer insight but would require some work, they can be exported as mentioned here and I could do the analysis?
so the delay is largely in kiwixlib, it might be beneficial to add logging to the task cancellation apk if you are still willing to test @dbedrenko but this may be tomorrow as I have a good few tickets to get to today.
Would be happy to test; no urgency, please take your time. I am really grateful that you give attention to this bug :)
It is quite technically challenging but in Android Studio there is a Profiler that can be run to collect CPU usage data, I am not too familiar with it and native code but it could offer insight but would require some work, they can be exported as mentioned here and I could do the analysis?
I will try to profile the app. My next hurdle is that Android Studio doesn't detect my device for some reason.
I see that adb
allows you to profile the app also; I will try this first.
@dbedrenko https://drive.google.com/file/d/10LPnhWsW11lwTQGbLTKBeJ4HkZXwSxrn/view?usp=sharing a task cancellation version with logging
I attach a log with the above version.
I am trying to make the profiling work: this should be very helpful. with-cancelling-and-logging.log
I have a profile trace of me searching for "shakes" with the cancel searches, logging enabled build.
This is how it looks like in Android Device Monitor (to run this tool, go to <YOUR-SDK-DIR>/tools
and run ./monitor
)
You can also open it in with Android Studio (this is how it looks like) and select the thread to analyse at the top left. It's weird that here you don't see all the columns that were in the Android Device Monitor like "Excl. CPU Time %". I guess they are buried somewhere in the interface...
The trace doesn't make sense to me, how is the "Incl CPU Time %" column not adding up to 100% ? Does it make sense to you?
I attach a log with the above version.
I am trying to make the profiling work: this should be very helpful. with-cancelling-and-logging.log
Oh how very annoying, the task cancellation isn't cancelling the tasks. I have a few options here 1 which I like but could make things a bit more complex overall and another I hate but keeps the ugly in this file.
1) Introduce coroutines to the project, their ease of cancellability is much touted, they are the future of async programming on Android but RxJava is fulfilling a similar role right now so we would have 2 competing tools. 2) Just start a thread for searching so when I kill it it actually gets killed
My opinion is probably not informed, but if one option is much easier to do than the other, I would do that one first to see if this actually fixes the slow search bug (remember, most people get instantaneous search results even without search cancellation). If it doesn't solve it, you don't have to merge it and we would look for the solution elsewhere.
https://drive.google.com/file/d/10LPnhWsW11lwTQGbLTKBeJ4HkZXwSxrn/view?usp=sharing
If you can try this version, coroutines with logging. Coroutines ended up being the nicest to implement with the finest grain of control. Thanks for your continued patience and assistance
Sorry for the delay, here is the log and the trace for search term "faceboo":
coroutines-with-logging.log coroutines-with-logging.trace.zip
This was the first search after starting the app. It took around 25 seconds from last letter touched to search results. Does the profiling trace illuminate anything? Thank you for not giving up on this issue :-)
If I do searches after that they are a lot quicker: around 15 seconds for "mango", 15 seconds for "john", 8 seconds for "bloke", 6 seconds for "shakespeare", 15 seconds for "google" (the duration is from the last letter touched to search results appearing).
07-30 20:33:11.511 E/SEARCH_BUG( 8370): before searchSuggestions for f
07-30 20:33:31.621 E/SEARCH_BUG( 8370): after searchSuggestions for f
07-30 20:33:31.621 E/SEARCH_BUG( 8370): before searchSuggestions for fa
07-30 20:33:31.628 E/SEARCH_BUG( 8370): before searchSuggestions for face
07-30 20:33:31.644 E/SEARCH_BUG( 8370): before searchSuggestions for faceboo
This has actually uncovered something a little interesting.
I assume in the 20 seconds between typing "f" and reaching "after searchSuggestions" for "f" you had typed the rest of "faceboo".
In a typical situation I would expect to see multiple "before searchSuggestions" arrive. This leads me to believe only a singular thread is free? Otherwise the other operations would just start and not be blocked by "searchsuggestions f"
Additional threads in this pool are created and are shutdown on demand. The number of threads used by this dispatcher is limited by the value of “kotlinx.coroutines.io.parallelism” (IO_PARALLELISM_PROPERTY_NAME) system property. It defaults to the limit of 64 threads or the number of cores (whichever is larger).
or you have a device with a single core? Doesn't seem likely.
I can try one more thing before I need to take a look at maybe re-implementing search suggestion from kiwixlib in kotlin as a cancellable suspend function? Which may very well be infeasible.
Unfortunately it will be monday before I can come back to this and hopefully dive into the traces
or you have a device with a single core? Doesn't seem likely.
My tablet has a dual-core CPU: "Dual-core 1.0 GHz Cortex-A9" to be exact.
@macgills Any feedback here? Would like to know if you need anything from libkiwix.
I think to resolve this I would need for the kiwixlib api offer me a way to instead of doing 1 call searchSuggestions(searchTerm, 200)
that blocks execution I would need something I can call iteratively so that execution returns to my control and I can call yield
or ensureActive
which will actually halt the execution entirely so the thread can stop.
I still haven't really analysed the CPU trace, it is hard to fit in to the daily routine of reviews, notification clearings, etc as it is a lengthy enough task. Buying the device in question might be feasible, I also have a budget alcatel device that might have 2 cores? It barely turns on it has so little memory though so that is always an annoying process.
Describe the bug Slow search function. Takesna minute or 2 and sometimes never for the search results to come out.
Expected behavior Quick search suggestion and results come out lile in the older 2.5 version
Steps to reproduce the behavior:
Environment